[MXS-2773] SkySQL: Maxscale 2.4.2 takes longer to allow connections after restart compared to 2.3.9 - Jira

XML

Word

Printable

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Fixed
Affects Version/s: None
Fix Version/s: 2.3.15
Component/s: Core
Labels:
- SkySQLMVP

Description

Summary:
We had identified an increase of the MaxScale 2.4 start-up time compared to MaxScale 2.3 Seems like restarting in 2.4 is much slower than 2.3 and even after the restart it seems to not allow queries for about 60s (compared to about 5s for 2.3).

Sample Problematic Scenatio:
topology: 1 maxsclae with 1 mariadb server behind it.
We start a sysbech test with N threads in order to have a load on the server.
We delete the maxscale pod.
Kubernetes starts a new maxscale pod.
After the restart we re-add the mariadb server to maxscale (done with a script, so it's within 2-3 seconds of maxscale restarting).

Impact:
With maxscale 2.3, about 5-6 seconds after the pod deletion, the new maxscale takes over and properly routes the queries.
With maxscale 2.4 (tested with 2.4.0, 2.4.2 and 2.4.4) it takes about 60s before the new maxscale routes the queries correctly.
Interestingly, when looking at "maxctrl list servers", maxscale reports that the mariadb server is up and running and has N connections to it, but the queries just don't seem to go through.I'm pretty sure we are hitting an issue with users_refresh_time=0 in 2.4
W've tested without it, and the problem is gone.
Unfortunately we need this setting for the time being in order to work around https://jira.mariadb.org/browse/MXS-2745

For 2.4 we use users_refresh_time=0, which should be an invalid value, but we need it to work around https://jira.mariadb.org/browse/MXS-2745
For 2.3 we do not set users_refresh_time, so it uses the default value, which is also 0, due to a known bug in 2.3

Logs for reference:

sysbench log for maxscale 2.4

[ 1s ] thds: 16 tps: 138.21 qps: 4221.87 (r/w/o: 3800.28/421.59/0.00) lat (ms,95%): 155.80 err/s: 0.00 reconn/s: 0.00

[ 2s ] thds: 16 tps: 144.30 qps: 4208.79 (r/w/o: 3776.89/431.90/0.00) lat (ms,95%): 170.48 err/s: 0.00 reconn/s: 0.00

[ 3s ] thds: 16 tps: 191.56 qps: 5531.22 (r/w/o: 4958.55/572.68/0.00) lat (ms,95%): 127.81 err/s: 0.00 reconn/s: 0.00

[ 4s ] thds: 16 tps: 162.58 qps: 4870.30 (r/w/o: 4386.58/483.72/0.00) lat (ms,95%): 167.44 err/s: 0.00 reconn/s: 0.00

[ 5s ] thds: 16 tps: 172.75 qps: 4911.78 (r/w/o: 4393.54/518.24/0.00) lat (ms,95%): 132.49 err/s: 0.00 reconn/s: 0.00

[ 6s ] thds: 16 tps: 111.75 qps: 3237.87 (r/w/o: 2902.61/335.26/0.00) lat (ms,95%): 179.94 err/s: 0.00 reconn/s: 0.00

[ 7s ] thds: 16 tps: 144.56 qps: 4305.76 (r/w/o: 3872.07/433.69/0.00) lat (ms,95%): 179.94 err/s: 0.00 reconn/s: 0.00

[ 8s ] thds: 16 tps: 128.01 qps: 3502.14 (r/w/o: 3118.13/384.02/0.00) lat (ms,95%): 176.73 err/s: 0.00 reconn/s: 0.00

[ 9s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 10s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 11s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 12s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 13s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 14s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 15s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 16s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 17s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 18s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 19s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 20s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 21s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 22s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 23s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 24s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 25s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 26s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 27s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 28s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 29s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 30s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 31s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 32s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 33s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 34s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 35s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 36s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 37s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 38s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 39s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 40s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 41s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 42s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 43s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 44s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 45s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 46s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 47s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 48s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 49s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 50s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 51s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 52s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 53s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 54s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 55s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 56s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 57s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 58s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 59s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 60s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 61s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 62s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 63s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 64s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 65s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 66s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 67s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 68s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 69s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 70s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 71s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 72s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 73s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 74s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 75s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 76s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 77s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 78s ] thds: 16 tps: 132.07 qps: 4245.37 (r/w/o: 3838.14/407.23/0.00) lat (ms,95%): 69758.52 err/s: 0.00 reconn/s: 16.01

[ 79s ] thds: 16 tps: 207.03 qps: 5946.93 (r/w/o: 5336.83/610.10/0.00) lat (ms,95%): 102.97 err/s: 0.00 reconn/s: 0.00

[ 80s ] thds: 16 tps: 176.00 qps: 5002.96 (r/w/o: 4474.97/528.00/0.00) lat (ms,95%): 144.97 err/s: 0.00 reconn/s: 0.00

[ 81s ] thds: 16 tps: 154.46 qps: 4439.99 (r/w/o: 3973.66/466.33/0.00) lat (ms,95%): 153.02 err/s: 0.00 reconn/s: 0.00

[ 82s ] thds: 16 tps: 131.14 qps: 3906.68 (r/w/o: 3516.31/390.36/0.00) lat (ms,95%): 158.63 err/s: 0.00 reconn/s: 0.00

[ 83s ] thds: 16 tps: 190.00 qps: 5461.86 (r/w/o: 4887.87/573.99/0.00) lat (ms,95%): 97.55 err/s: 0.00 reconn/s: 0.00

[ 84s ] thds: 16 tps: 176.02 qps: 4911.50 (r/w/o: 4387.45/524.05/0.00) lat (ms,95%): 144.97 err/s: 0.00 reconn/s: 0.00

– maxscale log
Note the "Host '10.16.2.209' blocked for 60 seconds due to too many authentication failures."

Version:    2.4.2-1

Git commit: 98e1ce004f593c86653a41451861f8c1eacf1acb

Built:      2019-11-04_10:46:35

Info : MaxScale will be run in the terminal process.

Configuration file : /etc/maxscale-cfg/maxscale.cnf

Log directory      : /var/log/maxscale

Data directory     : /var/lib/maxscale

Module directory   : /usr/lib/x86_64-linux-gnu/maxscale

Service cache      : /var/cache/maxscale

2019-11-18 12:52:30   notice : syslog logging is enabled.

2019-11-18 12:52:30   notice : maxlog logging is enabled.

2019-11-18 12:52:30   notice : Using up to 1.10GiB of memory for query classifier cache

2019-11-18 12:52:30   notice : The collection of SQLite memory allocation statistics turned off.

2019-11-18 12:52:30   notice : Threading mode of SQLite set to Multi-thread.

2019-11-18 12:52:30   notice : MariaDB MaxScale 2.4.2 started (Commit: aad4148d77bf2dfbaa0042bc45abda30c101cad2)

2019-11-18 12:52:30   notice : MaxScale is running in process 20

2019-11-18 12:52:30   notice : Configuration file: /etc/maxscale-cfg/maxscale.cnf

2019-11-18 12:52:30   notice : Log directory: /var/log/maxscale

2019-11-18 12:52:30   notice : Data directory: /var/lib/maxscale

2019-11-18 12:52:30   notice : Module directory: /usr/lib/x86_64-linux-gnu/maxscale

2019-11-18 12:52:30   notice : Service cache: /var/cache/maxscale

2019-11-18 12:52:30   notice : No query classifier specified, using default 'qc_sqlite'.

2019-11-18 12:52:30   notice : Loaded module qc_sqlite: V1.0.0 from /usr/lib/x86_64-linux-gnu/maxscale/libqc_sqlite.so

2019-11-18 12:52:30   notice : Query classification results are cached and reused. Memory used per thread: 560.83MiB

2019-11-18 12:52:30   notice : Loading /etc/maxscale-cfg/maxscale.cnf.

2019-11-18 12:52:30   notice : /etc/maxscale-cfg/maxscale.cnf.d does not exist, not reading.

2019-11-18 12:52:30   notice : Loaded module mariadbclient: V1.1.0 from /usr/lib/x86_64-linux-gnu/maxscale/libmariadbclient.so

2019-11-18 12:52:30   notice : [readwritesplit] Initializing statement-based read/write split router module.

2019-11-18 12:52:30   notice : Loaded module readwritesplit: V1.1.0 from /usr/lib/x86_64-linux-gnu/maxscale/libreadwritesplit.so

2019-11-18 12:52:30   notice : [readconnroute] Initialise readconnroute router module.

2019-11-18 12:52:30   notice : Loaded module readconnroute: V2.0.0 from /usr/lib/x86_64-linux-gnu/maxscale/libreadconnroute.so

2019-11-18 12:52:30   notice : [mariadbmon] Initialise the MariaDB Monitor module.

2019-11-18 12:52:30   notice : Loaded module mariadbmon: V1.5.0 from /usr/lib/x86_64-linux-gnu/maxscale/libmariadbmon.so

2019-11-18 12:52:30   notice : Encrypted password file /var/lib/maxscale/.secrets can't be accessed (No such file or directory). Password encryption is not used.

2019-11-18 12:52:30   notice : Loaded module mariadbauth: V1.1.0 from /usr/lib/x86_64-linux-gnu/maxscale/libmariadbauth.so

2019-11-18 12:52:30   notice : Started REST API on [127.0.0.1]:8989

2019-11-18 12:52:30   notice : MaxScale started with 2 worker threads, each with a stack size of 8388608 bytes.

2019-11-18 12:52:30   notice : Starting a total of 2 services...

2019-11-18 12:52:30   notice : Listening for connections at [0.0.0.0]:4006

2019-11-18 12:52:30   notice : Service 'Read-Write-Service' started (1/2)

2019-11-18 12:52:30   notice : Listening for connections at [0.0.0.0]:4008

2019-11-18 12:52:30   notice : Service 'Read-Only-Service' started (2/2)

2019-11-18 12:52:30   warning: Removing stale journal file for monitor 'MariaDB-Monitor'.

2019-11-18 12:52:30   warning: [mariadbmon] Tried to find a master but no valid master server found.

2019-11-18 12:52:30   error  : [mariadbmon] No Master can be determined

2019-11-18 12:52:32   warning: (1) [MariaDBAuth] Read-Write-Service: login attempt for user 'skysql_admin'@[10.16.2.211]:47282, authentication failed. User not found.

2019-11-18 12:52:32   warning: (2) [MariaDBAuth] Read-Write-Service: login attempt for user 'skysql_admin'@[10.16.2.211]:47284, authentication failed. User not found.

2019-11-18 12:52:32   warning: (3) [MariaDBAuth] Read-Write-Service: login attempt for user 'skysql_admin'@[10.16.2.211]:47286, authentication failed. User not found.

2019-11-18 12:52:32   warning: (4) [MariaDBAuth] Read-Write-Service: login attempt for user 'skysql_admin'@[10.16.2.211]:47288, authentication failed. User not found.

2019-11-18 12:52:32   warning: (5) [MariaDBAuth] Read-Write-Service: login attempt for user 'skysql_admin'@[10.16.2.211]:47292, authentication failed. User not found.

2019-11-18 12:52:32   warning: (6) [MariaDBAuth] Read-Write-Service: login attempt for user 'skysql_admin'@[10.16.2.211]:47294, authentication failed. User not found.

2019-11-18 12:52:32   warning: (7) [MariaDBAuth] Read-Write-Service: login attempt for user 'skysql_admin'@[10.16.2.211]:47296, authentication failed. User not found.

2019-11-18 12:52:32   warning: (8) [MariaDBAuth] Read-Write-Service: login attempt for user 'skysql_admin'@[10.16.2.211]:47194, authentication failed. User not found.

2019-11-18 12:52:32   warning: (17) [MariaDBAuth] Read-Write-Service: login attempt for user 'skysql_admin'@[10.16.2.211]:47210, authentication failed. User not found.

2019-11-18 12:52:32   warning: (10) [MariaDBAuth] Read-Write-Service: login attempt for user 'skysql_admin'@[10.16.2.211]:47208, authentication failed. User not found. (subsequent similar messages suppressed for 10000 milliseconds)

2019-11-18 12:52:32   notice : (9) Host '10.16.2.211' blocked for 60 seconds due to too many authentication failures.

2019-11-18 12:52:32   notice : (22) Host '10.16.2.211' blocked for 60 seconds due to too many authentication failures.

2019-11-18 12:52:32   notice : Loaded module MariaDBBackend: V2.0.0 from /usr/lib/x86_64-linux-gnu/maxscale/libmariadbbackend.so

2019-11-18 12:52:32   notice : Loaded module mariadbbackendauth: V1.0.0 from /usr/lib/x86_64-linux-gnu/maxscale/libmariadbbackendauth.so

2019-11-18 12:52:32   notice : Loaded server states from journal file: /var/lib/maxscale/MariaDB-Monitor/monitor.dat

2019-11-18 12:52:32   notice : Added server '10.16.4.5' to monitor 'MariaDB-Monitor'

2019-11-18 12:52:32   notice : Added server '10.16.4.5' to service 'Read-Only-Service'

2019-11-18 12:52:32   notice : Added server '10.16.4.5' to service 'Read-Write-Service'

2019-11-18 12:52:32   notice : Server '10.16.4.5' version: 10.4.8-3-MariaDB-enterprise-log

2019-11-18 12:52:32   notice : [mariadbmon] Selecting new master server.

2019-11-18 12:52:32   notice : [mariadbmon] Setting '10.16.4.5' as master.

2019-11-18 12:52:32   notice : Server changed state: 10.16.4.5[10.16.4.5:3306]: new_master. [Running] -> [Master, Running]

2019-11-18 12:52:33   notice : Updated 'passive' from 'true' to 'false'

2019-11-18 12:52:36   notice : Create network user 'admin_tmp'

OK

OK

2019-11-18 12:52:38   notice : Deleted network user 'admin_tmp'

OK

for reference, sysbench logs for 2.3
it reconnects much quicker

[ 18s ] thds: 16 tps: 191.58 qps: 5482.06 (r/w/o: 4924.27/557.78/0.00) lat (ms,95%): 99.33 err/s: 0.00 reconn/s: 0.00

[ 19s ] thds: 16 tps: 131.29 qps: 3836.51 (r/w/o: 3429.61/406.90/0.00) lat (ms,95%): 170.48 err/s: 0.00 reconn/s: 0.00

[ 20s ] thds: 16 tps: 173.01 qps: 5032.44 (r/w/o: 4525.39/507.04/0.00) lat (ms,95%): 137.35 err/s: 0.00 reconn/s: 0.00

[ 21s ] thds: 16 tps: 161.88 qps: 4717.38 (r/w/o: 4207.77/509.61/0.00) lat (ms,95%): 144.97 err/s: 0.00 reconn/s: 0.00

[ 22s ] thds: 16 tps: 45.03 qps: 1117.79 (r/w/o: 1006.72/111.08/0.00) lat (ms,95%): 121.08 err/s: 0.00 reconn/s: 0.00

[ 23s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 24s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 25s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 26s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 27s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 28s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 29s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 30s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 31s ] thds: 16 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00

[ 32s ] thds: 16 tps: 14.00 qps: 407.06 (r/w/o: 365.05/42.01/0.00) lat (ms,95%): 62.19 err/s: 0.00 reconn/s: 1.00

[ 33s ] thds: 16 tps: 23.00 qps: 685.02 (r/w/o: 616.02/69.00/0.00) lat (ms,95%): 53.85 err/s: 0.00 reconn/s: 0.00

and the maxscale logs. Note there is no 60 seconds block

Version:    2.3.9-0

Git commit: 74143ba6a955d0c58468185fefc199530ddc3faf

Built:      2019-08-30_09:39:22

Info : MaxScale will be run in the terminal process.

Configuration file : /etc/maxscale-cfg/maxscale.cnf

Log directory      : /var/log/maxscale

Data directory     : /var/lib/maxscale

Module directory   : /usr/lib/x86_64-linux-gnu/maxscale

Service cache      : /var/cache/maxscale

2019-11-18 13:05:11   notice : syslog logging is enabled.

2019-11-18 13:05:11   notice : maxlog logging is enabled.

2019-11-18 13:05:11   notice : Using up to 1.10GiB of memory for query classifier cache

2019-11-18 13:05:11   notice : The collection of SQLite memory allocation statistics turned off.

2019-11-18 13:05:11   notice : Threading mode of SQLite set to Multi-thread.

2019-11-18 13:05:11   notice : MariaDB MaxScale 2.3.9 started (Commit: 66d6ce6fa598a43b20af052ef6c9f637a3279fa1)

2019-11-18 13:05:11   notice : MaxScale is running in process 19

2019-11-18 13:05:11   notice : Configuration file: /etc/maxscale-cfg/maxscale.cnf

2019-11-18 13:05:11   notice : Log directory: /var/log/maxscale

2019-11-18 13:05:11   notice : Data directory: /var/lib/maxscale

2019-11-18 13:05:11   notice : Module directory: /usr/lib/x86_64-linux-gnu/maxscale

2019-11-18 13:05:11   notice : Service cache: /var/cache/maxscale

2019-11-18 13:05:11   notice : No query classifier specified, using default 'qc_sqlite'.

2019-11-18 13:05:11   notice : Loaded module qc_sqlite: V1.0.0 from /usr/lib/x86_64-linux-gnu/maxscale/libqc_sqlite.so

2019-11-18 13:05:11   notice : Query classification results are cached and reused. Memory used per thread: 560.83MiB

2019-11-18 13:05:11   notice : Loading /etc/maxscale-cfg/maxscale.cnf.

2019-11-18 13:05:11   notice : /etc/maxscale-cfg/maxscale.cnf.d does not exist, not reading.

2019-11-18 13:05:11   notice : Initialise the MariaDB Monitor module.

2019-11-18 13:05:11   notice : Loaded module mariadbmon: V1.5.0 from /usr/lib/x86_64-linux-gnu/maxscale/libmariadbmon.so

2019-11-18 13:05:11   notice : Loaded module mariadbclient: V1.1.0 from /usr/lib/x86_64-linux-gnu/maxscale/libmariadbclient.so

2019-11-18 13:05:11   notice : Initializing statement-based read/write split router module.

2019-11-18 13:05:11   notice : Loaded module readwritesplit: V1.1.0 from /usr/lib/x86_64-linux-gnu/maxscale/libreadwritesplit.so

2019-11-18 13:05:11   notice : Initialise readconnroute router module.

2019-11-18 13:05:11   notice : Loaded module readconnroute: V2.0.0 from /usr/lib/x86_64-linux-gnu/maxscale/libreadconnroute.so

2019-11-18 13:05:11   notice : Loaded module MySQLAuth: V1.1.0 from /usr/lib/x86_64-linux-gnu/maxscale/libmysqlauth.so

2019-11-18 13:05:11   notice : Housekeeper thread started.

2019-11-18 13:05:11   warning: Removing stale journal file for monitor 'MariaDB-Monitor'.

2019-11-18 13:05:11   notice : Encrypted password file /var/lib/maxscale/.secrets can't be accessed (No such file or directory). Password encryption is not used.

2019-11-18 13:05:11   notice : Starting a total of 2 services...

2019-11-18 13:05:11   notice : Listening for connections at [0.0.0.0]:4006 with protocol MySQL

2019-11-18 13:05:11   notice : Service 'Read-Write-Service' started (1/2)

2019-11-18 13:05:11   notice : Listening for connections at [0.0.0.0]:4008 with protocol MySQL

2019-11-18 13:05:11   notice : Service 'Read-Only-Service' started (2/2)

2019-11-18 13:05:11   warning: No valid master server found.

2019-11-18 13:05:11   error  : No Master can be determined

2019-11-18 13:05:11   notice : Started REST API on [127.0.0.1]:8989

2019-11-18 13:05:11   notice : MaxScale started with 2 worker threads, each with a stack size of 8388608 bytes.

2019-11-18 13:05:12   notice : Loaded module MariaDBBackend: V2.0.0 from /usr/lib/x86_64-linux-gnu/maxscale/libmariadbbackend.so

2019-11-18 13:05:12   notice : Loaded module MySQLBackendAuth: V1.0.0 from /usr/lib/x86_64-linux-gnu/maxscale/libmysqlbackendauth.so

2019-11-18 13:05:12   notice : Created server '10.16.4.6' at 10.16.4.6:3306

2019-11-18 13:05:12   notice : Loaded server states from journal file: /var/lib/maxscale/MariaDB-Monitor/monitor.dat

2019-11-18 13:05:12   notice : Added server '10.16.4.6' to monitor 'MariaDB-Monitor'

2019-11-18 13:05:12   notice : Added server '10.16.4.6' to service 'Read-Only-Service'

2019-11-18 13:05:12   notice : Added server '10.16.4.6' to service 'Read-Write-Service'

2019-11-18 13:05:12   notice : Selecting new master server.

2019-11-18 13:05:12   notice : Setting '10.16.4.6' as master.

2019-11-18 13:05:12   notice : Server changed state: 10.16.4.6[10.16.4.6:3306]: new_master. [Running] -> [Master, Running]

2019-11-18 13:05:13   notice : Updated 'passive' from 'true' to 'false'

2019-11-18 13:05:17   notice : Create network user 'admin_tmp'

OK

2019-11-18 13:05:17   notice : Deleted network user 'admin'

2019-11-18 13:05:17   notice : Create network user 'admin'

OK

2019-11-18 13:05:18   notice : Deleted network user 'admin_tmp'

OK

Attachments

Activity

People

Assignee:: markus makela

Reporter:: Nedyalko Petrov (Inactive)

Votes:: 0 Vote for this issue

Watchers:: 4 Start watching this issue

Dates

Created:: 2019-11-18 13:41

Updated:: 2019-12-02 06:51

Resolved:: 2019-12-02 06:51

Git Integration

Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.