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

Excessive logging by MySQLAuth at authentication error (was: MySQLAuth SQLite database can be permanently locked)

    Details

      Description

      A user reported that MaxScale is constantly reporting messages like the following:

      2018-02-06 16:47:33   error  : [MySQLAuth] Failed to execute auth query: database is locked
      

      It seems like their instance has gotten to the point where the SQLite database used for auth data is permanently locked. Here is a larger section of the log:

      2018-02-06 16:47:32   error  : [MySQLAuth] Client hostname lookup failed, getnameinfo() returned: 'Name or service not known'.
      2018-02-06 16:47:33   warning: [MySQLAuth] Splitter Service: login attempt for user 'user1'@[10.1.1.73]:59938, authentication failed.
      2018-02-06 16:47:33   warning: [MySQLAuth] Splitter Service: login attempt for user 'user1'@[10.1.1.73]:59940, authentication failed.
      2018-02-06 16:47:33   warning: [MySQLAuth] Splitter Service: login attempt for user 'user1'@[10.1.1.73]:59942, authentication failed.
      2018-02-06 16:47:33   warning: [MySQLAuth] Splitter Service: login attempt for user 'user1'@[10.1.1.73]:59944, authentication failed.
      2018-02-06 16:47:33   warning: [MySQLAuth] Splitter Service: login attempt for user 'user1'@[10.1.1.73]:59946, authentication failed.
      2018-02-06 16:47:33   warning: [MySQLAuth] Splitter Service: login attempt for user 'user1'@[10.1.1.73]:59948, authentication failed.
      2018-02-06 16:47:33   warning: [MySQLAuth] Splitter Service: login attempt for user 'user1'@[10.1.1.72]:48736, authentication failed.
      2018-02-06 16:47:33   warning: [MySQLAuth] Splitter Service: login attempt for user 'user1'@[10.1.1.72]:48738, authentication failed.
      2018-02-06 16:47:33   warning: [MySQLAuth] Splitter Service: login attempt for user 'user1'@[10.1.1.72]:48740, authentication failed.
      2018-02-06 16:47:33   warning: [MySQLAuth] Splitter Service: login attempt for user 'user1'@[10.1.1.72]:48742, authentication failed. (subsequent similar messages suppressed for 10000 milliseconds)
      2018-02-06 16:47:33   error  : [MySQLAuth] Failed to execute auth query: database is locked
      2018-02-06 16:47:33   error  : [MySQLAuth] Failed to execute auth query: database is locked
      2018-02-06 16:47:33   error  : [Splitter Service] Refresh rate limit exceeded for load of users' table.
      2018-02-06 16:47:33   error  : [MySQLAuth] Failed to execute auth query: database is locked
      2018-02-06 16:47:33   error  : [MySQLAuth] Failed to execute auth query: database is locked
      2018-02-06 16:47:33   error  : [Splitter Service] Refresh rate limit exceeded for load of users' table.
      2018-02-06 16:47:33   error  : [MySQLAuth] Failed to execute auth query: database is locked
      2018-02-06 16:47:33   error  : [MySQLAuth] Failed to execute auth query: database is locked
      2018-02-06 16:47:33   error  : [Splitter Service] Refresh rate limit exceeded for load of users' table.
      2018-02-06 16:47:34   error  : [MySQLAuth] Failed to execute auth query: database is locked
      2018-02-06 16:47:34   error  : [MySQLAuth] Failed to execute auth query: database is locked
      2018-02-06 16:47:34   error  : [Splitter Service] Refresh rate limit exceeded for load of users' table.
      2018-02-06 16:47:34   error  : [MySQLAuth] Failed to execute auth query: database is locked
      2018-02-06 16:47:34   error  : [MySQLAuth] Failed to execute auth query: database is locked
      2018-02-06 16:47:34   error  : [Splitter Service] Refresh rate limit exceeded for load of users' table.
      2018-02-06 16:47:34   error  : [MySQLAuth] Failed to execute auth query: database is locked
      2018-02-06 16:47:34   error  : [MySQLAuth] Failed to execute auth query: database is locked
      2018-02-06 16:47:34   error  : [Splitter Service] Refresh rate limit exceeded for load of users' table.
      2018-02-06 16:47:34   error  : [MySQLAuth] Failed to execute auth query: database is locked
      2018-02-06 16:47:34   error  : [MySQLAuth] Failed to execute auth query: database is locked
      2018-02-06 16:47:34   error  : [Splitter Service] Refresh rate limit exceeded for load of users' table.
      2018-02-06 16:47:34   error  : [MySQLAuth] Failed to execute auth query: database is locked
      2018-02-06 16:47:34   error  : [MySQLAuth] Failed to execute auth query: database is locked
      2018-02-06 16:47:34   error  : [Splitter Service] Refresh rate limit exceeded for load of users' table.
      2018-02-06 16:47:34   error  : [MySQLAuth] Failed to execute auth query: database is locked
      2018-02-06 16:47:34   error  : [MySQLAuth] Failed to execute auth query: database is locked
      2018-02-06 16:47:34   error  : [Splitter Service] Refresh rate limit exceeded for load of users' table.
      2018-02-06 16:47:34   error  : [MySQLAuth] Failed to execute auth query: database is locked (subsequent similar messages suppressed for 10000 milliseconds)
      2018-02-06 16:47:34   error  : [MySQLAuth] Failed to execute auth query: database is locked (subsequent similar messages suppressed for 10000 milliseconds)
      2018-02-06 16:47:34   error  : [Splitter Service] Refresh rate limit exceeded for load of users' table. (subsequent similar messages suppressed for 10000 milliseconds)
      2018-02-06 16:47:37   error  : [MySQLAuth] Client hostname lookup failed, getnameinfo() returned: 'Name or service not known'.
      2018-02-06 16:47:42   error  : [MySQLAuth] Client hostname lookup failed, getnameinfo() returned: 'Name or service not known'.
      2018-02-06 16:47:44   warning: [MySQLAuth] Splitter Service: login attempt for user 'user2'@[10.1.1.85]:34992, authentication failed.
      2018-02-06 16:47:44   warning: [MySQLAuth] Splitter Service: login attempt for user 'user1'@[10.1.1.73]:60052, authentication failed.
      2018-02-06 16:47:44   warning: [MySQLAuth] Splitter Service: login attempt for user 'user1'@[10.1.1.73]:60054, authentication failed.
      2018-02-06 16:47:44   warning: [MySQLAuth] Splitter Service: login attempt for user 'user1'@[10.1.1.73]:60056, authentication failed.
      2018-02-06 16:47:44   warning: [MySQLAuth] Splitter Service: login attempt for user 'user1'@[10.1.1.72]:48848, authentication failed.
      2018-02-06 16:47:44   warning: [MySQLAuth] Splitter Service: login attempt for user 'user1'@[10.1.1.72]:48850, authentication failed.
      2018-02-06 16:47:44   warning: [MySQLAuth] Splitter Service: login attempt for user 'user1'@[10.1.1.72]:48852, authentication failed.
      2018-02-06 16:47:44   error  : [MySQLAuth] Failed to execute auth query: database is locked
      2018-02-06 16:47:44   error  : [MySQLAuth] Failed to execute auth query: database is locked
      

      Is this a bug, or is this a problem that is likely to happen under a certain scenario (e.g. a high rate of authentication failures or something like that)?

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                johan.wikman Johan Wikman
                Reporter:
                GeoffMontee Geoff Montee
              • Votes:
                0 Vote for this issue
                Watchers:
                2 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: