Upgrade from MySQL 5.1.41 to 5.1.49 breaks simple SQLAlchemy queries.

[Former user]

First of all, thank you for a wonderful ORM. It is mostly a joy developing with it.

When I upgraded from Ubuntu Lucid Lynx, 10.04, to Maverick Meerkat, 10.10, the other day, which included an upgrade of MySQL from 5.1.41 to 5.1.49, many of my simple SQLAlchemy (SA) queries began to falsely return empty sets.

When running with a MySQL 5.1.41 database, the attached script correctly returns the output shown in the attached output files, *5.1.41.txt.

However, as shown in the other attached output files, *5.1.49.txt, the same queries then return empty sets.

This also breaks when typed directly into the MySQL command line tool. Therefore, this can probably not be blamed on SA, but perhaps the query generator in SA should be updated?

[Former user]

Standalone demonstration script

[Former user]

I forgot to stress that if line 102 is commented out (so that there is only one participant in the activity), then the query in the demo script correctly finds that user.

[Mike Bayer]

things to look at:

1. current version of MySQL is 5.1.51. Have you tried that ?

2. Have you reproduced the issue with a raw SQL script ? That's the very first thing you do with a behavioral difference so obvious. You then report a bug to MySQL if confirmed.

3. I don't see the INSERT statements in your logs. Have you confirmed that the issue is not on the INSERT side ? (this would fall under #2)

4. Have you verified the MySQL installation doesn't have an issue ?

5. Did you try the latest MySQLdb DBAPI ? Alternate DBAPIs like OurSQL ?

The query itself is extremely simple so I don't see what could be done here if 5.1.49 is so severely broken, though I didn't notice anything in their changelog subsequent, which suggests this might be something more subtle.

[Former user]

Replying to zzzeek:

things to look at:

1. current version of MySQL is 5.1.51. Have you tried that ?

I am sorry, but I have not tried that (yet). I have only had time to try the Ubuntu packages so far.

2. Have you reproduced the issue with a raw SQL script ? That's the very first thing you do with a behavioral difference so obvious. You then report a bug to MySQL if confirmed.

3. I don't see the INSERT statements in your logs. Have you confirmed that the issue is not on the INSERT side ? (this would fall under #2)

I have now stripped away the superflous information from the logs, and ended up with a pure SQL script, which I have attached. I tried to tell you that I had tried the same in pure SQL, and that the results were the same.

I will see if I can reproduce this under MySQL 5.1.51 too, and if the behavior is still different, I was actually planning on reporting those results to MySQL.

4. Have you verified the MySQL installation doesn't have an issue ?

At least, I have not been able to observe any issues. I have now tried with a completely clean MySQL server install, where the old database files were moved away. And the server log seems OK enough:

101027 20:30:13 Note /usr/sbin/mysqld: Normal shutdown

101027 20:30:13 Note Event Scheduler: Purging the queue. 0 events 101027 20:30:15 InnoDB: Starting shutdown... 101027 20:30:19 InnoDB: Shutdown completed; log sequence number 0 68152 101027 20:30:19 Note /usr/sbin/mysqld: Shutdown complete

101027 20:30:43 Note Plugin 'FEDERATED' is disabled. 101027 20:30:43 InnoDB: Started; log sequence number 0 68152 101027 20:30:43 Note Event Scheduler: Loaded 0 events 101027 20:30:43 Note /usr/sbin/mysqld: ready for connections. Version: '5.1.49-1ubuntu8' socket: '/var/run/mysqld/mysqld.sock' port: 3306 (Ubuntu)

But, the strange behavior still occurs. I guess I have to move on to the 5.1.51 release then.

5. Did you try the latest MySQLdb DBAPI ? Alternate DBAPIs like OurSQL ?

I used MySQLdb version 1.2.3c1 and got the same behavior with OurSQL version 0.9.2. As I mentioned initially in my report, I observe this strange behavior independent of SQLAlchemy (that is, with "pure SQL") too, so I do not actually call this a bug in SQLAlchemy.

The query itself is extremely simple so I don't see what could be done here if 5.1.49 is so severely broken, though I didn't notice anything in their changelog subsequent, which suggests this might be something more subtle.

I absolutely agree. It may definitely be something wrong somewhere in my configuration, but (as far as I know) I have only used Ubuntu defaults.

I would also like to add that, in my experience, the database engine is generally never the cause of a problem. It real cause might be some misconfiguration or an application error, but in this case I have not been able to detect any such errors.

Thank you for your help so far.

[Mike Bayer]

Replying to guest:

I would also like to add that, in my experience, the database engine is generally never the cause of a problem. It real cause might be some misconfiguration or an application error, but in this case I have not been able to detect any such errors.

They are rare but I have seen database engine bugs with both SQLite and MySQL. MySQL more often, though not as rudimentary as this one.

[Former user]

Replying to guest:

Replying to zzzeek:

things to look at:

1. current version of MySQL is 5.1.51. Have you tried that ?

I am sorry, but I have not tried that (yet). I have only had time to try the Ubuntu packages so far.

Now, I have also tested this with version 5.1.51 of MySQL. An surprisingly enough (atleast to me), the results are the same as with version 5.1.49, tested with the "pure SQL" script that I recently attached to this ticket.

In an attempt to show how strange the result is, given the situation:

mysql> select version();
+-----------+
| version() |
+-----------+
| 5.1.51    |
+-----------+
1 row in set (0.00 sec)

mysql> select * from user;
+---------+--------+
| user_id | name   |
+---------+--------+
|       1 | Demo   |
|       2 | Demo 2 |
+---------+--------+
2 rows in set (0.00 sec)

mysql> select * from activity;
+-------------+------------+
| activity_id | name       |
+-------------+------------+
|           1 | writing #0 |
|           2 | writing #1 |
|           3 | writing #2 |
|           4 | writing #3 |
+-------------+------------+
4 rows in set (0.00 sec)

mysql> select * from activity_participant;
+-------------+---------+
| activity_id | user_id |
+-------------+---------+
|           1 |       2 |
|           2 |       2 |
|           3 |       2 |
|           4 |       2 |
|           2 |       1 |
|           4 |       1 |
+-------------+---------+
6 rows in set (0.00 sec)

mysql> SELECT activity.activity_id AS activity_activity_id, 
              activity.name AS activity_name  
       FROM activity, activity_participant AS activity_participant_1  
       WHERE activity.activity_id = 2 
         AND activity.activity_id = activity_participant_1.activity_id 
         AND 1 = activity_participant_1.user_id;
Empty set (0.00 sec)

mysql> EXPLAIN SELECT activity.activity_id AS activity_activity_id, 
                      activity.name AS activity_name 
       FROM activity, activity_participant AS activity_participant_1  
       WHERE activity.activity_id = 2 
         AND activity.activity_id = activity_participant_1.activity_id 
         AND 1 = activity_participant_1.user_id;
+----+-------------+------------------------+-------------+---------------------+---------------------+---------+-------+------+----------------------------------------------------------------+
| id | select_type | table                  | type        | possible_keys       | key                 | key_len | ref   | rows | Extra                                                          |
+----+-------------+------------------------+-------------+---------------------+---------------------+---------+-------+------+----------------------------------------------------------------+
|  1 | SIMPLE      | activity               | const       | PRIMARY             | PRIMARY             | 4       | const |    1 |                                                                |
|  1 | SIMPLE      | activity_participant_1 | index_merge | activity_id,user_id | activity_id,user_id | 5,5     | NULL  |    1 | Using intersect(activity_id,user_id); Using where; Using index |
+----+-------------+------------------------+-------------+---------------------+---------------------+---------+-------+------+----------------------------------------------------------------+
2 rows in set (0.00 sec)

And, still no warnings or errors in the log. Hmm...

Thank you for your help so far.

[Mike Bayer]

take a look through http://bugs.mysql.com/search.php?search_for=wrong&status=Active&severity=&limit=All&order_by=&cmd=display&direction=ASC&bug_type=&os=0&phpver=&bug_age=0

in particular http://bugs.mysql.com/bug.php?id=56862 stood out a bit

[Former user]

Replying to zzzeek:

take a look through http://bugs.mysql.com/search.php?search_for=wrong&status=Active&severity=&limit=All&order_by=&cmd=display&direction=ASC&bug_type=&os=0&phpver=&bug_age=0

in particular http://bugs.mysql.com/bug.php?id=56862 stood out a bit

Thank you for the tip. I actually tried the patch in the bug report you mention in particular, but the results were the same. Since I did not find any other bug report that described the same situation, I followed your suggestion to submit a bug report to MySQL (http://bugs.mysql.com/bug.php?id=57795).

[Mike Bayer]

great, confirmed as a MySQL bug over there and also fixed.