[MXS-1661] Excessive logging by MySQLAuth at authentication error (was: MySQLAuth SQLite database can be permanently locked) Created: 2018-02-08 Updated: 2020-08-25 Resolved: 2018-02-12 |
|
| Status: | Closed |
| Project: | MariaDB MaxScale |
| Component/s: | Authenticator |
| Affects Version/s: | 2.1.13 |
| Fix Version/s: | 2.1.14, 2.2.2 |
| Type: | Bug | Priority: | Major |
| Reporter: | Geoff Montee (Inactive) | Assignee: | Johan Wikman |
| Resolution: | Fixed | Votes: | 0 |
| Labels: | None | ||
| Issue Links: |
|
||||||||||||
| Description |
|
A user reported that MaxScale is constantly reporting messages like the following:
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:
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)? |
| Comments |
| Comment by Johan Wikman [ 2018-02-09 ] | |
|
The database is locked indicates that two of MaxScale's worker threads simultaneously are trying to update the user database and it fails for either of them. It's the SQLITE_BUSY error explained here: https://sqlite.org/rescode.html#result_code_meanings In the log above there are two users user1 and user2 for which the authentication fails and if they happen to be handled by two separate worker threads, then that could be an explanation. Should the users user1 and user2 be able to access database? Can they, if MaxScale is not in between? In MaxScale 2.2 database is locked can no longer occur as each worker thread has an in-memory user database of its own. | |
| Comment by Johan Wikman [ 2018-02-09 ] | |
|
There are a couple of problems. When the refresh rate limit has been exceeded, then every failed authentication will cause that message to be logged. It should be logged at most once, until we try refreshing the users again. That's straightforward to fix and will prevent the log from being flooded with messages. Another thing is whether a failed authentication should at all trigger a refresh of the users. The idea is that if a user has been created, then if a failed authentication triggers a refresh of the users then MaxScale will automatically deal with new users. However, that leads to the problem here if there are logins with users who simply are not authorized. Perhaps it would be sufficient if MaxScale regularly (say once a minute, or 10 minutes) refreshes the users or perhaps not to refresh automatically at all but to provide a maxadmin/maxctrl command for doing it. | |
| Comment by Johan Wikman [ 2018-02-09 ] | |
|
The database is locked errors are caused by running two maxscale instances in the same machine, without
having been defined to different value for the two instances. Without that, if those two instances have a service with the same name, they will end up using the very same sqlite database for the users. That then leads to the aforementioned error when they independently and concurrently try to update the database. | |
| Comment by Johan Wikman [ 2018-02-12 ] | |
|
I'll rename this to Excessive logging by MySQLAuth at authentication error as the locking problem was caused by a user configuration error and the fixes that have been done addresses the excessive logging. There is now a task | |
| Comment by Johan Wikman [ 2018-02-12 ] | |
|
At startup, MaxScale loads all users from the backend. At runtime, when a user authentication fails, MaxScale assumes it is because a user has been created and reloads the users. During a time window of 30 seconds that could take place at most 4 times. Thereafter, each authentication failure caused a refresh rate exceeded error to be logged. If a client attempted to connect over and over again that would cause the log to be flooded until the flooding suppression mechanism hit in. This has now been changed so that the users are refreshed at most once during that time window and an error about the refresh rate having been exceeded will also be logged at most once. Further, the length of the time window can now be adjusted using the global configuration option users_refresh_time using which the runtime refreshing also can be turned off entirely, if it is known that users are not created at runtime. It is still possible to manually cause the users to be refreshed using maxadmin. |