Bug #13524 lock timeout gives incorrect warning on open cursor
Submitted: 27 Sep 2005 12:48 Modified: 24 Nov 2005 0:05
Reporter: Berto van de Kraats Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server Severity:S1 (Critical)
Version:5.0.14-rc-nightly-20050926 OS:Linux (Linux Suse SLES 9 FP 1)
Assigned to: Konstantin Osipov

[27 Sep 2005 12:48] Berto van de Kraats
Description:
If the following steps are done, then the fetch after the lock that times out gives incorrect warning messages.

1. Exclusively lock a row
2. Open a cursor
3. Attempt to lock the same row in a different session, which fails (time out)
4. Continue to fetch on the open cursor

How to repeat:
Compile and run the attached program. If the problem does not reproduce then it runs silently with exit status 0. If the problem reproduces then the output should be:

   !!! Error (297): 
     Expected value:0
     Returned value:2
      error: a.out: t1.cpp:297: int main(): Assertion `0' failed.
   Abort (core dumped) 

Set innodb_lock_wait_timeout to a low value, because the program will wait for a lock time out.
[27 Sep 2005 12:50] Berto van de Kraats
Cpp trace of problem

Attachment: bug13524.cpp (text/plain), 35.52 KiB.

[27 Sep 2005 13:52] Miguel Solorzano
miguel@hegel:~/dbs/5.0> ./bug13524
!!! Error (297): 
  Expected value:0
  Returned value:2
   error: bug13524: /home/miguel/dbs/5.0/bug13524.cpp:297: int main(): Assertion `0' failed.
Aborted
[10 Nov 2005 8:29] Konstantin Osipov
After fixing Bug#13488 I can't repeat the bug any more.
Here is the patched test case that I use, and the test passes:
Could you please check if the problem is still present in the latest tree?

kostja@dragonfly:~> diff -u bug13524.cpp bug13524.new.cpp 
--- bug13524.cpp	2005-11-10 11:23:44.000000000 +0300
+++ bug13524.new.cpp	2005-11-10 10:36:08.000000000 +0300
@@ -33,13 +33,13 @@
 // Connection parameters
 const char *MYSQL_CMD = "mysql"; // Used for table creation
 const char *HOST_NAME = NULL;
-const char *USER_NAME = "bsp";
-const char *USER_PWD = "bsp";
-const char *DB_NAME = "baan";
-const char *UNIX_SOCKET = "/var/lib/mysql/mysql.sock";
+const char *USER_NAME = "kostja";
+const char *USER_PWD = "";
+const char *DB_NAME = "test";
+const char *UNIX_SOCKET = "/opt/local/var/mysql/mysql.sock";
 // For ddl statements we use a different user/pwd
-const char *OWNER_NAME = "baan";
-const char *OWNER_PWD = "baan";
+const char *OWNER_NAME = "kostja";
+const char *OWNER_PWD = "";
 
 // use "#define M_EXPECT_EQUALS (void)" to disable data validation
 typedef enum { STR, SESS, STMT } ;
@@ -281,8 +281,8 @@
    m_ret = mysql_stmt_attr_set(stmt_5,STMT_ATTR_CURSOR_TYPE,(const void *) &select_cursor); M_EXPECT_EQUALS(0,m_ret,STMT,stmt_5);
    m_text = "SELECT table_name FROM table_locks WHERE table_name = 'tdbtst120280' LOCK IN SHARE MODE";
    m_ret = mysql_stmt_prepare(stmt_5,m_text,strlen(m_text)); M_EXPECT_EQUALS( 0,m_ret,STMT,stmt_5 );
-   m_ret = mysql_stmt_execute(stmt_5); M_EXPECT_EQUALS( 1,m_ret,STMT,stmt_5 );
-   m_ret = mysql_stmt_errno(stmt_5); M_EXPECT_EQUALS( 1205,m_ret,STMT,stmt_5 ); // Lock wait timeout exceeded; try restarting transaction
+   m_ret = mysql_stmt_execute(stmt_5); M_EXPECT_EQUALS( 0,m_ret,STMT,stmt_5 );
+   m_ret = mysql_stmt_errno(stmt_5); M_EXPECT_EQUALS( 0,m_ret,STMT,stmt_5 ); // Lock wait timeout exceeded; try restarting transaction
    mysql_stmt_close(stmt_5);
 
    // Continue fetching on the open cursor
[10 Nov 2005 10:36] Berto van de Kraats
I've downloaded the latest snapshot (mysql-5.0.16-nightly-20051109-linux-i686) and applied the patch for bug 13488 (http://lists.mysql.com/internals/32112), but the problem still reproduces on my system:

$ echo $MYSQLDIR
/usr1/mysql/mysql-5.0.16-nightly-20051109-linux-i686
$ gcc -g -I $MYSQLDIR/include /home/bvdkraat/bug13524.cpp $MYSQLDIR/lib/libmysqlclient.a -lm -lz -lstdc++
$ ./a.out
!!! Error (297): 
  Expected value:0
  Returned value:2
   error: a.out: /home/bvdkraat/bug13524.cpp:297: int main(): Assertion `0' failed.
Abort (core dumped) 
$
[17 Nov 2005 13:21] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/internals/32354
[17 Nov 2005 16:42] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/internals/32370
[17 Nov 2005 16:43] Konstantin Osipov
Fixed in 5.0 tree, currently tagged 5.0.17
[24 Nov 2005 0:05] Paul Dubois
Noted in 5.0.17 changelog.