Wouter, ----- Original Message ----- From: "Wouter Zelle" <[EMAIL PROTECTED]> Newsgroups: mailing.database.mysql Sent: Tuesday, September 03, 2002 7:43 PM Subject: InnoDB locks disappear
> My program uses locks to allow for multi-threading (processing > requests that are stored in the database using more than one thread > and/or application). The problem is that the locks disappear for > seemingly no reason at all. The same queries are repeated over and > over again until the lock just vanishes, so it seems to be a time-out > or something like that. I've created a log-file of the queries and > two reports from the innodb_lock_monitor, the one just before the > lock vanishes and the one after. the default for innodb_lock_wait_timeout is 50 seconds in recent versions. It may be that the manual at www.mysql.com is outdated and claims it is infinite. A lock wait timeout rolls back the whole transaction and releases all locks. You should check the return value of your queries and look if they are reporting lock wait timeouts or other errors. > I would really appreciate some help, > > Wouter Zelle Best regards, Heikki Tuuri Innobase Oy --- Order technical MySQL/InnoDB support at https://order.mysql.com/ See http://www.innodb.com for the online manual and latest news on InnoDB > ---Query log > -- Comments: > At the start of the fragment the request is being locked in > connection #23 (every request is locked in a seperate connection so > commits won't do harm anyone else). The next query (14:43:13) finds > all unprocessed requests in the DB (Connection #22 is used for this > query). The 'For Update'-query tries to lock the request and fails if > it is already locked (causing my app to move on to the next request). > Connection #24 is used for this kind of query after 14:43:18. As you > can see, the two types of requests keep interleaving until I halted > the app, which was after the request was unlocked. > > I've cleaned up the log a bit for easy reading. > --- > 14:42:42 23 Connect wouter@localhost on > 23 Init DB rosetta > 23 Query SHOW VARIABLES > 23 Query SET autocommit=0 > 23 Query SELECT [t0.columns] FROM REQUEST t0, > ROSETTA_USER T1 WHERE (t0.EXTERNAL_IDENTIFIER = 'RequestID01' AND > T1.LOGIN = 'login') AND t0.USER_ID = T1.USER_ID FOR UPDATE > 14:43:13 22 Query SELECT [t0.columns] FROM REQUEST t0 WHERE > t0.STATUS = 'ReadyForProcessing' ORDER BY t0.CREATION_DATE ASC > 22 Query commit > 14:43:18 24 Connect wouter@localhost on > 24 Init DB rosetta > 24 Query SHOW VARIABLES > 24 Query SET autocommit=0 > 24 Query SELECT [t0.columns] FROM REQUEST t0, > ROSETTA_USER T1 WHERE (t0.EXTERNAL_IDENTIFIER = 'RequestID01' AND > T1.LOGIN = 'login') AND t0.USER_ID = T1.USER_ID FOR UPDATE > 14:43:43 22 Query SELECT [t0.columns] FROM REQUEST t0 WHERE > t0.STATUS = 'ReadyForProcessing' ORDER BY t0.CREATION_DATE ASC > 22 Query commit > 14:44:12 24 Query SELECT [t0.columns] FROM REQUEST t0, > ROSETTA_USER T1 WHERE (t0.EXTERNAL_IDENTIFIER = 'RequestID01' AND > T1.LOGIN = 'login') AND t0.USER_ID = T1.USER_ID FOR UPDATE > 14:44:33 22 Query SELECT [t0.columns] FROM REQUEST t0 WHERE > t0.STATUS = 'ReadyForProcessing' ORDER BY t0.CREATION_DATE ASC > 22 Query commit > 14:44:53 24 Query SELECT [t0.columns] FROM REQUEST t0, > ROSETTA_USER T1 WHERE (t0.EXTERNAL_IDENTIFIER = 'RequestID01' AND > T1.LOGIN = 'login') AND t0.USER_ID = T1.USER_ID FOR UPDATE > 14:45:18 22 Query SELECT [t0.columns] FROM REQUEST t0 WHERE > t0.STATUS = 'ReadyForProcessing' ORDER BY t0.CREATION_DATE ASC > 22 Query commit > 14:45:24 24 Query SELECT [t0.columns] FROM REQUEST t0, > ROSETTA_USER T1 WHERE (t0.EXTERNAL_IDENTIFIER = 'RequestID01' AND > T1.LOGIN = 'login') AND t0.USER_ID = T1.USER_ID FOR UPDATE > 14:45:42 22 Query SELECT [t0.columns] FROM REQUEST t0 WHERE > t0.STATUS = 'ReadyForProcessing' ORDER BY t0.CREATION_DATE ASC > 22 Query commit > 14:45:54 24 Query SELECT [t0.columns] FROM REQUEST t0, > ROSETTA_USER T1 WHERE (t0.EXTERNAL_IDENTIFIER = 'RequestID01' AND > T1.LOGIN = 'login') AND t0.USER_ID = T1.USER_ID FOR UPDATE > 14:46:23 22 Query SELECT [t0.columns] FROM REQUEST t0 WHERE > t0.STATUS = 'ReadyForProcessing' ORDER BY t0.CREATION_DATE ASC > 22 Query commit > 14:46:41 24 Query SELECT [t0.columns] FROM REQUEST t0, > ROSETTA_USER T1 WHERE (t0.EXTERNAL_IDENTIFIER = 'RequestID01' AND > T1.LOGIN = 'login') AND t0.USER_ID = T1.USER_ID FOR UPDATE > 14:47:08 22 Query SELECT [t0.columns] FROM REQUEST t0 WHERE > t0.STATUS = 'ReadyForProcessing' ORDER BY t0.CREATION_DATE ASC > 14:47:09 22 Query commit > 23 Quit > 14:47:28 3 Query DROP TABLE innodb_lock_monitor > ---End Query Log > > ---INNODB MONITOR OUTPUT > -- Comments: > I took out everything but the transactions, since I don't think the > rest will be of any help. If you need some other info, please ask. > -- > --- > ===================================== > 14:47:06 INNODB MONITOR OUTPUT > ===================================== > ------------ > TRANSACTIONS > ------------ > Trx id counter 0 370112 > Purge done for trx's n:o < 0 370096 undo n:o < 0 0 > Total number of lock structs in row lock hash table 2 > LIST OF TRANSACTIONS FOR EACH SESSION: > ---TRANSACTION 0 370111, not started, OS thread id 1660 > MySQL thread id 24, query id 1036 localhost 127.0.0.1 wouter > ---TRANSACTION 0 370110, not started, OS thread id 1636 > MySQL thread id 22, query id 1035 localhost 127.0.0.1 wouter > ---TRANSACTION 0 370099, ACTIVE 264 sec, OS thread id 292 > 4 lock struct(s), heap size 320 > MySQL thread id 23, query id 1015 localhost 127.0.0.1 wouter > TABLE LOCK table rosetta/request trx id 0 370099 lock_mode IX > RECORD LOCKS space id 0 page no 50 n bits 80 table rosetta/request > index PRIMARY > trx id 0 370099 lock_mode X > Record lock, heap no 1 RECORD: info bits 0 0: len 9; hex > 73757072656d756d00; asc > supremum.;; > Record lock, heap no 2 RECORD: info bits 0 0: len 8; hex > 80000000000000c5; asc . > .......;; 1: > Record lock, heap no 10 RECORD: info bits 0 0: len 8; hex 80000000000000e8; asc > .......Þ;; 1: > Suppressing further record lock prints for this page > TABLE LOCK table rosetta/rosetta_user trx id 0 370099 lock_mode IX > RECORD LOCKS space id 0 page no 53 n bits 288 table > rosetta/rosetta_user index P > RIMARY trx id 0 370099 lock_mode X > Record lock, heap no 220 RECORD: info bits 0 0: len 8; hex > 8000000000000d28; asc > .......(;; 1: > ---------------------------- > END OF INNODB MONITOR OUTPUT > ============================ > > ===================================== > 14:47:22 INNODB MONITOR OUTPUT > ===================================== > ------------ > TRANSACTIONS > ------------ > Trx id counter 0 370113 > Purge done for trx's n:o < 0 370096 undo n:o < 0 0 > Total number of lock structs in row lock hash table 0 > LIST OF TRANSACTIONS FOR EACH SESSION: > ---TRANSACTION 0 370111, not started, OS thread id 1660 > MySQL thread id 24, query id 1036 localhost 127.0.0.1 wouter > ---TRANSACTION 0 370112, not started, OS thread id 1636 > MySQL thread id 22, query id 1038 localhost 127.0.0.1 wouter > ---------------------------- > END OF INNODB MONITOR OUTPUT > ============================ > -- > > --------------------------------------------------------------------- > Before posting, please check: > http://www.mysql.com/manual.php (the manual) > http://lists.mysql.com/ (the list archive) > > To request this thread, e-mail <[EMAIL PROTECTED]> > To unsubscribe, e-mail <[EMAIL PROTECTED]> > Trouble unsubscribing? Try: http://lists.mysql.com/php/unsubscribe.php > > --------------------------------------------------------------------- Before posting, please check: http://www.mysql.com/manual.php (the manual) http://lists.mysql.com/ (the list archive) To request this thread, e-mail <[EMAIL PROTECTED]> To unsubscribe, e-mail <[EMAIL PROTECTED]> Trouble unsubscribing? Try: http://lists.mysql.com/php/unsubscribe.php
