Bug #5569 Incorrect "Access Denied" error with SAME login DIFFERENT host
Submitted: 14 Sep 2004 12:49 Modified: 8 Feb 2005 19:47
Reporter: Emmanuel KARTMANN Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server Severity:S3 (Non-critical)
Version:4.0.20 OS:Windows (Windows 2000)
Assigned to: Jim Winstead CPU Architecture:Any

[14 Sep 2004 12:49] Emmanuel KARTMANN
Description:
I have a INCORRECT "Access Denied" error from time to time on a production system. I know the error is incorrect because the login/password is always OK, and the error occurs "randomly".

This error occurs only when a different host tries to access the database server (not when accessing from localhost) - but when the "access denied" error occurs, the login seems to be "corrupted" and all future connections fails (even with correct login/password and valid access rights).

When the login is corrupted, the command "FLUSH PRIVILEGES" fixes the problem - connection succeeds again.

It seems that the MySQL Server uses a cache for access control - but it uses it in a bad way, rejecting a perfectly valid connection request! FLUSH PRIVILEGES clears the cache, fixing the bug (but then the cache is filled up the error occurs again!).

Note that it is very hard to reproduce this bug - you need 2 hosts, 2 databases and pattern matching access rights (% in a GRANT command).

How to repeat:
It took me and my team many days to analyse and reproduce this bug out of our production system. Here is the process...

You need to have 2 hosts, one with MySQL Server (call it MyServer) and one with the MySQL command line client (call it "MyClient"). MyServer has IP address 192.168.1.2 while myClient has IP address 192.168.1.3 (Ip addresses ARE IMPORTANT in the test; please adapt the scripts if you have different IPs on you LAN).

You need to setup a test environment, with 2 databases and one login which have access to both database from specific addresses. Here is the SQL Script which creates this environment:

  -- Cleanup database and login
  DROP DATABASE IF EXISTS mydb1
  ;
  DROP DATABASE IF EXISTS mydb2
  ;
  DELETE FROM mysql.user
  WHERE User='mylogin'
  ;
  DELETE FROM mysql.db
  WHERE user='mylogin'
  ;

  FLUSH PRIVILEGES
  ;

  -- Create database 1, table and set login/access
  CREATE DATABASE mydb1
  ;
  CREATE TABLE mydb1.mytable(
    id INTEGER NOT NULL AUTO_INCREMENT, 
    label VARCHAR(255),
    PRIMARY KEY(id)
  )
  ;
  INSERT INTO mydb1.mytable(label) 
    VALUES('mydb1.mytable label 1'), ('mydb1.mytable label 2')
  ;
  -- Grant access on mydb1 to mylogin BUT from a specific SUBNET (%)
  GRANT
    ALL PRIVILEGES 
  ON 
    mydb1.* 
  TO 
    'mylogin'@'127.0.0.1'
  IDENTIFIED BY 
    'mypassword'
  ;

  -- Create database 2 (empty), table and set login/access
  CREATE DATABASE mydb2
  ;

  -- Grant access on mydb2 to mylogin BUT from a specific SUBNET (%) where client DOES belong
  GRANT
    ALL PRIVILEGES 
  ON 
    mydb2.* 
  TO 
    'mylogin'@'192.168.1.%'
  IDENTIFIED BY 
    'mypassword'
  ;

  FLUSH PRIVILEGES
  ;

Once the two databases are setup, you need to execute the following command (from a command prompt) in that order:

(1) SERVER TO SERVER is OK

MyServer> C:\mysql\bin\mysql.exe --host=127.0.0.1 --user=mylogin --password=mypassword --database=mydb1 --execute="SELECT * FROM mytable"
+----+-----------------------+
| id | label                 |
+----+-----------------------+
|  1 | mydb1.mytable label 1 |
|  2 | mydb1.mytable label 2 |
+----+-----------------------+

(2) CLIENT TO SERVER is DENIED, but this is normal according to GRANTs

MyClient> C:\mysql\bin\mysql.exe --host=192.168.1.2 --user=mylogin --password=mypassword --database=mydb1 --execute="SELECT * FROM mytable"
ERROR 1044: Access denied for user: 'mylogin@192.168.1.%' to database 'mydb1'

This error apparently CORRUPTS the authentication cache - login "mylogin" is now corrupted!

(3) SERVER TO SERVER is DENIED now (it should be allowed as in step 1!)

MyServer> C:\mysql\bin\mysql.exe --host=127.0.0.1 --user=mylogin --password=mypassword --database=mydb1 --execute="SELECT * FROM mytable"
ERROR 1044: Access denied for user: 'mylogin@127.0.0.1' to database 'mydb1'

If you execute the SQL command "FLUSH PRIVILEGES" now, connecting from SERVER TO SERVER will work again...

Suggested fix:
Fix the cache so that it won't lock access after one remote "Access Denied" error.
[6 Oct 2004 4:21] Erik Perrohe
Ahh, the light dawns...

I believe that I have seen a similar/same problem when using a single linux computer.  Every now and then mysqld would get into a funk, in which I simply could not login until I did a restart.  

Drove me a bit nuts trying to solve the problem.  Since then I have learned to be very careful about how I login.

I was running the server on an alternate port and specifying the host ip.
[6 Oct 2004 19:36] Matthew Lord
Hi,

Thank you for an excellent bug report!

This looks like it's specific to 4.0 on windows.  I was able to verify this with 4.0.21 on windows 
2000.  I was *NOT* able to duplicate the problem with 4.0.21 or 4.1.5 on linux (Linux booty 
2.4.21 #12 SMP Thu Aug 14 00:49:40 EDT 2003 i686 i686 i386 GNU/Linux) and I was *NOT* able 
to reproduce it with 4.1.5 on windows 2000.
[7 Oct 2004 13:59] MySQL Verification Team
Matt,

I tested this and can't repeat between 2 machines windows: win98/xp.

step 1

c:\mysql\bin>mysql.exe --host=127.0.0.1 --user=mylogin --password=mypassword --database=mydb1 --execute="SELECT * FROM mytab
le"
+----+-----------------------+
| id | label                 |
+----+-----------------------+
|  1 | mydb1.mytable label 1 |
|  2 | mydb1.mytable label 2 |
+----+-----------------------+

after the access denied from client machine:

c:\mysql\bin>mysql.exe --host=127.0.0.1 --user=mylogin --password=mypassword --database=mydb1 --execute="SELECT * FROM mytab
le"
+----+-----------------------+
| id | label                 |
+----+-----------------------+
|  1 | mydb1.mytable label 1 |
|  2 | mydb1.mytable label 2 |
+----+-----------------------+

I am using IP: 192.168.0.% instead of 192.168.1.% if this matter.
[8 Oct 2004 0:09] Matthew Lord
I could repeat the problem using mysqld-nt.exe --no-defaults, same with mysqld-opt and mysqld-
max-nt.  I could not, however, repeat the problem using mysqld.exe.  That means that I cannot 
create a stack trace easily, which would be very helpful.
[8 Oct 2004 0:29] MySQL Verification Team
I can confirm what Matt found. The issue only happens on releases versions
servers.
[5 Nov 2004 1:06] MySQL Verification Team
Tested on 4.1.7 without to present the bug reported. So only
4.0.XX is affected.
[12 Nov 2004 16:27] Brian Aker
Thank you for taking the time to report a problem.  Unfortunately
you are not using a current version of the product your reported a
problem with -- the problem might already be fixed. Please download
a new version from http://www.mysql.com/downloads/

If you are able to reproduce the bug with one of the latest versions,
please change the version on this bug report to the version you
tested and change the status back to "Open".  Again, thank you for
your continued support of MySQL.
[12 Nov 2004 16:54] Brian Aker
Second thought, lets see if we can fix this in 4.0 (though it does not appear to be a bug in the 
latest production 4.1).
[19 Nov 2004 8:28] Emmanuel KARTMANN
Thank you Brian - fixing the bug in 4.0x would be great.

I would love to upgrade to MySQL 4.1, but I have one (and maybe more!) issue because I'm accessing MySQL via MyODBC 3.51.9 and we can't connect due to a new hash algorithm (and NO, and don't want to stick to the old algorithm as a workaround! what's the point of upgrading if you're stuck with the old bugs?).

Is there a planning/schedule for a MyODBC 4.x that would support/connect to MySQL 4.1?
[8 Dec 2004 12:00] Steven Hartland
I can confirm this is still happening on 4.1.7 under FreeBSD.
Our senario is that we have ~ 100 machines connected to our central DB each of which logs to 2 seperate tables once per minute. 1 row into out machine log table and 0..* rows to our server log table.
The behaviour we are seeing is that random machines will report the error:
Failed to insert server log row ( insert command denied to user 'username'@'hostname' for table 'gf_server_log' )
or
Failed to insert machine log row ( insert command denied to user 'username'@'hostname' for table 'gf_machine_log' )
There doesnt seem to be any pattern to the error i.e. it may happen after just a few mins of running or it may happen after serveral hours. But in the end all our loggers stop processing.

This behaviour has only started since our upgrade yesterday to 4.1.7 from 4.0.x.
This may be a seperate issue but the details are so close I doubt it.
Server is running on FreeBSD 4.8-RELEASE-p16 compiled with:
make WITH_LINUXTHREADS=yes DB_DIR=/usr/local/mysql
also tried:
make WITH_LINUXTHREADS=yes BUILD_OPTIMIZED=yes BUILD_STATIC=yes DB_DIR=/usr/local/mysql
But this was totally unstable sig 11's and out of memory errors.
Clients vary most are FreeBSD 5.2.1 using 4.0 client libs via perl DBI/DBD.

With the regularity of failure I would say this may need to be raised in prority.
[8 Dec 2004 13:26] Steven Hartland
Now been running with a compile without linuxthreads and all is looking good.
Linux threads version was: 2.2.3_13
New build with just:
make DB_DIR=/usr/local/mysql
[8 Dec 2004 17:33] Steven Hartland
Spoke too soon. Although a huge amount better we just had our first failure 5 hours later its seems to be related to concurrency.
[9 Dec 2004 17:01] Steven Hartland
Confirmed that 4.0.22 doesnt suffer from this issue.
[3 Jan 2005 17:17] Emmanuel KARTMANN
I'm sorry but I CAN reproduce this bug on MySQL 4.0.22 - nothing has changed...

Any fix schedule?

Thanks in advance,

Regards,

E.
[19 Jan 2005 3:14] Pierre-Henry Perret
So is the software context:
System: FreeBSD 5.2.1
sofware installed: PHP5.0 / MySql 4.1 / Apache 2.0
_________________________________________________________________
PHP Warning:  mysql_connect()  Access denied for user:
'scribe@localhost' (Using password: YES) in config.inc.php on line 31
__________________________________________________

the config.inc.php file is :
_______________________________________

<?
/* identifications des serveurs */
$server = getenv("HTTP_HOST");

       //vars used for host serveur
        $dbhost = "localhost";
        $dblogin = "enseigne";
        $dbpass = "c9bv2MrV";
        $dbname = "enseigne";
       //vars pour la bible
        $dbhost2 = "localhost";
        $dblogin2 = "scribe";
        $dbpass2 = "_scribe_";
        $dbname2 = "bible";

/* conexion aux bases de donnée */
$connexion = mysql_connect ($dbhost,$dblogin,$dbpass);
/* conexion aux bases de donnée */
$connex_bible = mysql_connect ($dbhost2,$dblogin2,$dbpass2);

if (!$connexion || !$connex_bible) {
               echo "---> error.";
               exit;
}
/* Etape 2 : connexion à la base */
if (!mysql_select_db ($dbname, $connexion)) {
               echo "---> error";
}
if (!mysql_select_db ($dbname2, $connex_bible)) {
               echo "---> error";
}
?>
________________________________________________________

What is interesting is that this error seams to occur randomly.

Do you have a guess ?
Pierre
[20 Jan 2005 4:52] Jim Winstead
I've already verified that this only impacts the non-debug build of 4.0 on Microsoft Windows. Other similar-sounding problems are likely due to a different problem. (The problem on Windows is easily repeatable.)

(Note: Connector/ODBC 3.51.10 can be used to connect to MySQL 4.1 with new-style passwords.)
[21 Jan 2005 2:47] Jim Winstead
Part of the data being used to cache ACL lookups was not always being reinitialized properly, particularly for connections from localhost on Microsoft Windows.

This problem only exists in the 4.0 code -- different data is used for looking up cached ACL data in 4.1 and later versions, and it is initialized correctly.

Similar-sounding bugs on other platforms will need to reported as new bugs with repeatable test cases.
[2 Feb 2005 17:44] Jim Winstead
Pushed to 4.0.
[8 Feb 2005 19:47] Paul DuBois
Mentioned in 4.0.24 change notes.