Uploaded image for project: 'MariaDB MaxScale'
  1. MariaDB MaxScale
  2. MXS-2773

SkySQL: Maxscale 2.4.2 takes longer to allow connections after restart compared to 2.3.9

    XMLWordPrintable

    Details

      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 markus makela
            Reporter:
            nedyalko.petrov Nedyalko Petrov
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved: