Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
None
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
|