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

[readwritesplit] Could not find valid server for target type TARGET_MASTER, closing connection.

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed (View Workflow)
    • Priority: Major
    • Resolution: Cannot Reproduce
    • Affects Version/s: 2.4.17
    • Fix Version/s: N/A
    • Component/s: readwritesplit
    • Labels:
      None
    • Sprint:
      MXS-SPRINT-139

      Description

      On several occasions the message

      [readwritesplit] Could not find valid server for target type TARGET_MASTER, closing connection.
      

      showed up even though no master failures were seen in the maxscale log.

      The connector being used on the client side is MariaDB Connector/J on AIX

      The messages seem to be logged at times where we also see

      warning: Client requests unknown prepared statement ID '1' that does not map to an internal ID
      

      and

      warning: Using unknown prepared statement with ID 0
      

      but there can be a few seconds between these and the TARGET_MASTER messages.

      Here's a log snippet starting with maxscale start up to the first occurrence of such messages:

      MariaDB MaxScale  /var/log/maxscale/maxscale.log  Thu Jun  3 17:07:07 2021
      ----------------------------------------------------------------------------
      2021-06-03 17:07:07   notice : syslog logging is enabled.
      2021-06-03 17:07:07   notice : maxlog logging is enabled.
      2021-06-03 17:07:07   warning: Number of threads set to 192, which is greater than the hard maximum of 100. Number of threads adjusted down accordingly.
      2021-06-03 17:07:07   notice : Using up to 151.07GiB of memory for query classifier cache
      2021-06-03 17:07:07   notice : Working directory: /var/log/maxscale
      2021-06-03 17:07:07   notice : The collection of SQLite memory allocation statistics turned off.
      2021-06-03 17:07:07   notice : Threading mode of SQLite set to Multi-thread.
      2021-06-03 17:07:07   notice : MariaDB MaxScale 2.4.17 started (Commit: a8bfbbe254095d931aed351871fee72ce9ea645c)
      2021-06-03 17:07:07   notice : MaxScale is running in process 3882
      2021-06-03 17:07:07   notice : Configuration file: /etc/maxscale.cnf
      2021-06-03 17:07:07   notice : Log directory: /var/log/maxscale
      2021-06-03 17:07:07   notice : Data directory: /var/lib/maxscale
      2021-06-03 17:07:07   notice : Module directory: /usr/lib64/maxscale
      2021-06-03 17:07:07   notice : Service cache: /var/cache/maxscale
      2021-06-03 17:07:07   notice : Worker message queue size: 1.00MiB
      2021-06-03 17:07:07   notice : No query classifier specified, using default 'qc_sqlite'.
      2021-06-03 17:07:07   notice : Loaded module qc_sqlite: V1.0.0 from /usr/lib64/maxscale/libqc_sqlite.so
      2021-06-03 17:07:07   notice : Query classification results are cached and reused. Memory used per thread: 1.51GiB
      2021-06-03 17:07:07   notice : The systemd watchdog is Enabled. Internal timeout = 30s
      2021-06-03 17:07:07   notice : Loading /etc/maxscale.cnf.
      2021-06-03 17:07:07   notice : /etc/maxscale.cnf.d does not exist, not reading.
      2021-06-03 17:07:07   notice : Runtime configuration changes have been done to MaxScale. Loading persisted configuration files and applying them on top of the main configuration file. These changes can override the values of the main configuration file: To revert them, remove all the files in '/var/lib/maxscale/maxscale.cnf.d'.
      2021-06-03 17:07:07   notice : Loading /var/lib/maxscale/maxscale.cnf.d/core-monitor.cnf.
      [...]
      2021-06-03 17:07:07   notice : Loading /var/lib/maxscale/maxscale.cnf.d/ibs-coredb-dr2.cnf.
      2021-06-03 17:07:07   notice : Loaded module mariadbbackend: V2.0.0 from /usr/lib64/maxscale/libmariadbbackend.so
      2021-06-03 17:07:07   notice : Loaded module mariadbclient: V1.1.0 from /usr/lib64/maxscale/libmariadbclient.so
      2021-06-03 17:07:07   notice : [readconnroute] Initialise readconnroute router module.
      2021-06-03 17:07:07   notice : Loaded module readconnroute: V2.0.0 from /usr/lib64/maxscale/libreadconnroute.so
      2021-06-03 17:07:07   notice : Loaded module hintfilter: V1.0.0 from /usr/lib64/maxscale/libhintfilter.so
      2021-06-03 17:07:07   notice : Loaded module topfilter: V1.0.1 from /usr/lib64/maxscale/libtopfilter.so
      2021-06-03 17:07:07   notice : Loaded module qlafilter: V1.1.1 from /usr/lib64/maxscale/libqlafilter.so
      2021-06-03 17:07:07   warning: Missing slashes (/) around a regular expression is deprecated: 'exclude=select|show|set|commit|use|'.
      2021-06-03 17:07:07   warning: Missing quotes (") around a quoted string is deprecated: 'separator=,'.
      2021-06-03 17:07:07   notice : [readwritesplit] Initializing statement-based read/write split router module.
      2021-06-03 17:07:07   notice : Loaded module readwritesplit: V1.1.0 from /usr/lib64/maxscale/libreadwritesplit.so
      2021-06-03 17:07:07   notice : [mariadbmon] Initialise the MariaDB Monitor module.
      2021-06-03 17:07:07   notice : Loaded module mariadbmon: V1.5.0 from /usr/lib64/maxscale/libmariadbmon.so
      2021-06-03 17:07:07   notice : Loaded module mariadbbackendauth: V1.0.0 from /usr/lib64/maxscale/libmariadbbackendauth.so
      2021-06-03 17:07:07   notice : Encrypted password file /var/lib/maxscale/.secrets can't be accessed (No such file or directory). Password encryption is not used.
      2021-06-03 17:07:07   notice : Loaded module mariadbauth: V1.1.0 from /usr/lib64/maxscale/libmariadbauth.so
      2021-06-03 17:07:07   notice : Started REST API on [127.0.0.1]:8989
      2021-06-03 17:07:07   notice : MaxScale started with 100 worker threads, each with a stack size of 8388608 bytes.
      2021-06-03 17:07:07   notice : Starting a total of 2 services...
      2021-06-03 17:07:07   notice : Server 'ibs-coredb-dc1' charset: utf8
      2021-06-03 17:07:07   notice : Server 'ibs-coredb-dc1' version: 10.5.9-6-MariaDB-enterprise-log
      2021-06-03 17:07:07   notice : Server 'ibs-coredb-dc2' charset: utf8
      2021-06-03 17:07:07   notice : Server 'ibs-coredb-dc2' version: 10.5.9-6-MariaDB-enterprise-log
      2021-06-03 17:07:07   notice : [MariaDBAuth] [RW-Service-core] Loaded 576 MySQL users for listener 'RW-listener-core' from server 'ibs-coredb-dc1' with checksum 0xa8b8f9ac.
      2021-06-03 17:07:07   notice : Listening for connections at [::]:43306
      2021-06-03 17:07:07   notice : Service 'RW-Service-core' started (1/2)
      2021-06-03 17:07:07   notice : Server 'ibs-coredb-dc4' charset: utf8
      2021-06-03 17:07:07   notice : Server 'ibs-coredb-dc4' version: 10.5.9-6-MariaDB-enterprise-log
      2021-06-03 17:07:07   notice : [MariaDBAuth] [ROL-Service-bsscore] Loaded 576 MySQL users for listener 'ROL-listener-bsscore' from server 'ibs-coredb-dc4' with checksum 0xa8b8f9ac.
      2021-06-03 17:07:07   notice : Listening for connections at [::]:43308
      2021-06-03 17:07:07   notice : Service 'ROL-Service-bsscore' started (2/2)
      2021-06-03 17:07:07   notice : Loaded server states from journal file: /var/lib/maxscale/core-monitor/monitor.dat
      2021-06-03 17:07:07   notice : Server 'ibs-coredb-dc3' charset: utf8
      2021-06-03 17:07:07   notice : Server 'ibs-coredb-dc3' version: 10.5.9-6-MariaDB-enterprise-log
      2021-06-03 17:07:07   notice : Server 'ibs-coredb-dr1' charset: utf8
      2021-06-03 17:07:07   notice : Server 'ibs-coredb-dr1' version: 10.5.9-6-MariaDB-enterprise-log
      2021-06-03 17:07:07   notice : Server 'ibs-coredb-dr2' charset: utf8
      2021-06-03 17:07:07   notice : Server 'ibs-coredb-dr2' version: 10.5.9-6-MariaDB-enterprise-log
      2021-06-03 17:12:35   notice : (1) [MariaDBAuth] [RW-Service-core] Loaded 576 MySQL users for listener 'RW-listener-core' from server 'ibs-coredb-dc2' with checksum 0x1a0e3cc9.
      2021-06-03 17:12:35   warning: (1) [MariaDBAuth] RW-Service-core: login attempt for user 'kui'@[::ffff:10.0.10.37]:41670, authentication failed. Wrong password.
      2021-06-03 21:13:17   notice : Loaded server states from journal file: /var/lib/maxscale/core-monitor/monitor.dat
      2021-06-03 21:13:21   notice : Loaded server states from journal file: /var/lib/maxscale/core-monitor/monitor.dat
      2021-06-03 21:13:21   notice : Loaded server states from journal file: /var/lib/maxscale/core-monitor/monitor.dat
      2021-06-03 22:20:41   notice : Updated service 'RW-Service-core': transaction_replay=true
      2021-06-03 22:21:13   notice : Updated service 'RW-Service-core': transaction_replay_max_size=200Mi
      2021-06-03 22:21:42   notice : Updated service 'RW-Service-core': transaction_replay_attempts=10
      2021-06-03 22:22:30   notice : Updated service 'RW-Service-core': transaction_replay_retry_on_deadlock=true
      2021-06-03 22:24:04   notice : Updated service 'RW-Service-core': transaction_replay_max_size=500Mi
      2021-06-03 23:42:55   notice : Updated 'passive' from 'false' to 'true'
      2021-06-03 23:43:42   notice : Updated 'passive' from 'true' to 'false'
      2021-06-04 07:45:45   warning: Client requests unknown prepared statement ID '1' that does not map to an internal ID
      2021-06-04 07:45:45   warning: Client requests unknown prepared statement ID '1' that does not map to an internal ID
      2021-06-04 07:45:45   warning: Using unknown prepared statement with ID 0
      2021-06-04 07:45:45   warning: Using unknown prepared statement with ID 0
      2021-06-04 07:45:45   warning: Client requests unknown prepared statement ID '1' that does not map to an internal ID
      2021-06-04 07:45:45   warning: Using unknown prepared statement with ID 0
      2021-06-04 07:45:45   warning: Client requests unknown prepared statement ID '1' that does not map to an internal ID
      2021-06-04 07:45:45   warning: Client requests unknown prepared statement ID '1' that does not map to an internal ID
      2021-06-04 07:45:45   warning: Client requests unknown prepared statement ID '1' that does not map to an internal ID
      2021-06-04 07:45:45   warning: Client requests unknown prepared statement ID '1' that does not map to an internal ID
      2021-06-04 07:45:45   warning: Client requests unknown prepared statement ID '1' that does not map to an internal ID
      2021-06-04 07:45:45   warning: Using unknown prepared statement with ID 0
      2021-06-04 07:45:45   warning: Client requests unknown prepared statement ID '1' that does not map to an internal ID
      2021-06-04 07:45:45   warning: Using unknown prepared statement with ID 0
      2021-06-04 07:45:45   warning: Using unknown prepared statement with ID 0
      2021-06-04 07:45:45   warning: Using unknown prepared statement with ID 0
      2021-06-04 07:45:45   warning: Using unknown prepared statement with ID 0
      2021-06-04 07:45:45   warning: Using unknown prepared statement with ID 0
      2021-06-04 07:45:45   warning: Client requests unknown prepared statement ID '1' that does not map to an internal ID (subsequent similar messages suppressed for 10000 milliseconds)
      2021-06-04 07:45:45   warning: Using unknown prepared statement with ID 0 (subsequent similar messages suppressed for 10000 milliseconds)
      2021-06-04 07:45:54   error  : [readwritesplit] Could not find valid server for target type TARGET_MASTER, closing connection.
      2021-06-04 07:45:54   error  : [readwritesplit] Could not find valid server for target type TARGET_MASTER, closing connection.
      2021-06-04 07:45:54   error  : [readwritesplit] Could not find valid server for target type TARGET_MASTER, closing connection.
      2021-06-04 07:45:54   error  : [readwritesplit] Could not find valid server for target type TARGET_MASTER, closing connection.
      2021-06-04 07:45:54   error  : [readwritesplit] Could not find valid server for target type TARGET_MASTER, closing connection.
      2021-06-04 07:45:54   error  : [readwritesplit] Could not find valid server for target type TARGET_MASTER, closing connection.
      2021-06-04 07:45:54   error  : [readwritesplit] Could not find valid server for target type TARGET_MASTER, closing connection.
      2021-06-04 07:45:54   error  : [readwritesplit] Could not find valid server for target type TARGET_MASTER, closing connection.
      2021-06-04 07:45:54   error  : [readwritesplit] Could not find valid server for target type TARGET_MASTER, closing connection.
      2021-06-04 07:45:54   error  : [readwritesplit] Could not find valid server for target type TARGET_MASTER, closing connection. (subsequent similar messages suppressed for 10000 milliseconds)
      [...]
      

      There are two servers known to the readwritesplit routers, neither of their error logs showed anything special at the times these messages were logged on the maxscale side.

      We unfortunately also don't have any hint yet towards what queries may have been causing this.

        Attachments

          Activity

            People

            Assignee:
            markus makela markus makela
            Reporter:
            hholzgra Hartmut Holzgraefe
            Votes:
            1 Vote for this issue
            Watchers:
            5 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved:

                Git Integration