Activity log for bug #673105

Date Who What changed Old value New value Message
2010-11-09 17:05:06 Patrick Crews bug added bug
2010-11-09 17:06:29 Patrick Crews drizzle: assignee David Shrewsbury (dshrews)
2010-11-09 17:06:32 Patrick Crews drizzle: status New Confirmed
2010-11-09 17:07:06 Patrick Crews tags replication
2010-11-09 17:44:24 Patrick Crews attachment added tarball with various log files / sql to help troubleshoot. https://bugs.launchpad.net/drizzle/+bug/673105/+attachment/1728129/+files/bug673105.tar.gz
2010-11-10 16:20:11 David Shrewsbury drizzle: status Confirmed In Progress
2010-11-10 16:20:27 David Shrewsbury drizzle: importance Undecided Critical
2010-11-10 17:07:07 Patrick Crews attachment added text files showing what was happening with all transactions and the failing thread's queries https://bugs.launchpad.net/drizzle/+bug/673105/+attachment/1729251/+files/bad_output.tar.gz
2010-11-10 20:47:35 Patrick Crews attachment added dumpfile that gets the DB into a state *just prior* to the offending queries https://bugs.launchpad.net/drizzle/+bug/673105/+attachment/1729531/+files/bug673105_dump.tar.gz
2010-11-11 21:28:00 Patrick Crews description When testing Drizzle's transaction log in a concurrent environment with the randgen, we are seeing differences between the server's state and the SQL captured in the transaction log. The failures appear to be the results of INSERT's, UPDATE's, and DELETE's. The test consists of executing several queries (in several threads) against the server. We then generate SQL from the transaction log and use the SQL to populate a validation server. We compare Drizzledump output between 'master' and 'slave' to validate. The failure is generally consistent, but appears to be subject to timing issues. The randgen fork()'s off processes for each 'thread' used and the exact timing and interaction between threads varies. However, we see failures at certain thread/query_count combinations: 2 threads, 2500 queries 5 threads, 70-75 queries 10 thread, 50 queries. This test grammar was designed to produce a higher percentage of valid queries and tables can easily grow quite large. At present, I am not certain what is causing the issue, but it is an interaction between connections. These failures are not repeatable in single-thread scenarios. TO REPEAT: 1) Start a drizzle server to test, enable the transaction log ./test-run --start-and-exit --drizzled=--transaction-log.enable (expected port 9306) 2) Start a second server to validate (expected port 9307) 3) Run the randgen and observe the results. Command line: perl ./gentest.pl \ --dsn=dbi:drizzle:host=localhost:port=9306:user=root:password="":database=test \ --gendata=conf/drizzle/translog_drizzle.zz --grammar=conf/drizzle/translog_concurrent3.yy \ --queries=70 --threads=5 --sqltrace --debug --Reporter=DrizzleConcurrentTransactionLog Sample output: # 2010-11-09T11:51:18 Executing diff --unified /tmp//translog_rpl_dump_4869_9306.sql /tmp//translog_rpl_dump_4869_9307.sql --- /tmp//translog_rpl_dump_4869_9306.sql 2010-11-09 11:51:17.981424189 -0500 +++ /tmp//translog_rpl_dump_4869_9307.sql 2010-11-09 11:51:18.491212405 -0500 @@ -1014,21 +1014,46 @@ INSERT INTO `a` VALUES (NULL,'a','u',6,'7073747639715495936','b','','GHGTD',8,'you','mean',1143,'b','RZARM','UUDDE','UKVQC','','','1147292005072633856','BSUXB',6,8,'there','',NULL); INSERT INTO `a` VALUES (NULL,'q','z',6,'7891995397013372928','e','','JFLJB',NULL,'okay','SALOT',1144,'t','ZPJCL','z','NMCDY','','','7','want',1,1,'TLLTD','',NULL); INSERT INTO `a` VALUES (NULL,'q','z',6,'7891995397013372928','e','','JFLJB',NULL,'okay','SALOT',1145,'t','ZPJCL','z','NMCDY','','','7','want',1,1,'TLLTD','',NULL); +INSERT INTO `a` VALUES ('-7326793643778375680','h','m',1383792640,'6322209451898044416','v','','MZTZG',NULL,'will','he',1146,'u','MYQYS','I','that\'s','','','-7835700401671241728','k',6,3,'HMCNM','','6'); +INSERT INTO `a` VALUES ('-6968194523448999936','i','t',-1211891712,'-6355704974126612480','o','','j',NULL,'LQVCJ','we',1147,'c','could','MWBTI','I\'ll','','','3','that',0,-988217344,'CCQZH','','8'); INSERT INTO `a` VALUES (NULL,'q','z',6,'7891995397013372928','e','','JFLJB',NULL,'okay','SALOT',1148,'t','ZPJCL','z','NMCDY','','','7','want',1,126,'TLLTD','',NULL); +INSERT INTO `a` VALUES ('-6968194523448999936','i','t',-1211891712,'-6355704974126612480','o','','j',NULL,'LQVCJ','we',1149,'c','could','MWBTI','I\'ll','','','3','that',0,-988217344,'CCQZH','','8'); +INSERT INTO `a` VALUES ('-6882063180575539200','v','q',NULL,'6230167134513659904','e','','who',-351141888,'t','k',1150,'x','yes','l','s','','','8706302504637300736','y',-1453522944,5,'NTVJG','','287104476244869120'); When testing Drizzle's transaction log in a concurrent environment with the randgen, we are seeing differences between the server's state and the SQL captured in the transaction log. The failures appear to be the results of INSERT's, UPDATE's, and DELETE's. The test consists of executing several queries (in several threads) against the server. We then generate SQL from the transaction log and use the SQL to populate a validation server. We compare Drizzledump output between 'master' and 'slave' to validate. The failure is generally consistent, but appears to be subject to timing issues. The randgen fork()'s off processes for each 'thread' used and the exact timing and interaction between threads varies. However, we see failures at certain thread/query_count combinations: 2 threads, 2500 queries 5 threads, 70-75 queries 10 thread, 50 queries. This test grammar was designed to produce a higher percentage of valid queries and tables can easily grow quite large. At present, I am not certain what is causing the issue, but it is an interaction between connections. These failures are not repeatable in single-thread scenarios. TO REPEAT: 1) Start a drizzle server to test, enable the transaction log ./test-run --start-and-exit --drizzled=--transaction-log.enable (expected port 9306) --basedir=$PWD/.. 2) Start a second server to validate (expected port 9307) 3) Run the randgen and observe the results. Command line: perl ./gentest.pl \ --dsn=dbi:drizzle:host=localhost:port=9306:user=root:password="":database=test \ --gendata=conf/drizzle/translog_drizzle.zz --grammar=conf/drizzle/translog_concurrent3.yy \  --queries=70 --threads=5 --sqltrace --debug --Reporter=DrizzleConcurrentTransactionLog Sample output: # 2010-11-09T11:51:18 Executing diff --unified /tmp//translog_rpl_dump_4869_9306.sql /tmp//translog_rpl_dump_4869_9307.sql --- /tmp//translog_rpl_dump_4869_9306.sql 2010-11-09 11:51:17.981424189 -0500 +++ /tmp//translog_rpl_dump_4869_9307.sql 2010-11-09 11:51:18.491212405 -0500 @@ -1014,21 +1014,46 @@  INSERT INTO `a` VALUES (NULL,'a','u',6,'7073747639715495936','b','','GHGTD',8,'you','mean',1143,'b','RZARM','UUDDE','UKVQC','','','1147292005072633856','BSUXB',6,8,'there','',NULL);  INSERT INTO `a` VALUES (NULL,'q','z',6,'7891995397013372928','e','','JFLJB',NULL,'okay','SALOT',1144,'t','ZPJCL','z','NMCDY','','','7','want',1,1,'TLLTD','',NULL);  INSERT INTO `a` VALUES (NULL,'q','z',6,'7891995397013372928','e','','JFLJB',NULL,'okay','SALOT',1145,'t','ZPJCL','z','NMCDY','','','7','want',1,1,'TLLTD','',NULL); +INSERT INTO `a` VALUES ('-7326793643778375680','h','m',1383792640,'6322209451898044416','v','','MZTZG',NULL,'will','he',1146,'u','MYQYS','I','that\'s','','','-7835700401671241728','k',6,3,'HMCNM','','6'); +INSERT INTO `a` VALUES ('-6968194523448999936','i','t',-1211891712,'-6355704974126612480','o','','j',NULL,'LQVCJ','we',1147,'c','could','MWBTI','I\'ll','','','3','that',0,-988217344,'CCQZH','','8');  INSERT INTO `a` VALUES (NULL,'q','z',6,'7891995397013372928','e','','JFLJB',NULL,'okay','SALOT',1148,'t','ZPJCL','z','NMCDY','','','7','want',1,126,'TLLTD','',NULL); +INSERT INTO `a` VALUES ('-6968194523448999936','i','t',-1211891712,'-6355704974126612480','o','','j',NULL,'LQVCJ','we',1149,'c','could','MWBTI','I\'ll','','','3','that',0,-988217344,'CCQZH','','8'); +INSERT INTO `a` VALUES ('-6882063180575539200','v','q',NULL,'6230167134513659904','e','','who',-351141888,'t','k',1150,'x','yes','l','s','','','8706302504637300736','y',-1453522944,5,'NTVJG','','287104476244869120');
2010-11-12 23:06:03 Patrick Crews attachment added additional tarball for troubleshooting https://bugs.launchpad.net/drizzle/+bug/673105/+attachment/1731769/+files/bug674588.tar.gz
2010-12-17 19:44:26 Launchpad Janitor branch linked lp:~dshrews/drizzle/bug673105
2010-12-19 16:14:16 Lee Bieber nominated for series drizzle/elliott
2010-12-19 16:14:16 Lee Bieber bug task added drizzle/elliott
2010-12-19 16:14:54 Lee Bieber drizzle/elliott: status In Progress Fix Committed
2010-12-19 16:14:57 Lee Bieber drizzle/elliott: milestone 2010-12-20
2010-12-21 17:16:16 David Shrewsbury drizzle/elliott: milestone 2010-12-20 2011-01-17
2011-01-04 18:57:18 Lee Bieber drizzle/elliott: status Fix Committed Fix Released