MySQL Bugs: #47427: Why commit but not in my database

Bug #47427	Why commit but not in my database
Submitted:	18 Sep 4:23	Modified:	3 Oct 19:14
Reporter:	newbie Shai
Status:	Open
Category:	Server: InnoDB	Severity:	S1 (Critical)
Version:	5.0.67	OS:	Microsoft Windows
Assigned to:		Target Version:
Tags:	Commit not inserting the value

Description:
Dear All,
        I have a very funny scenario. I have system where it reads the value from another
db and updates my local db. I put the whole thing into a transaction it have been working
very fine. Suddenly I find in my log file as below for two different cases. I notice the
insert into product have been commited but when I check my databased this lines are not
there. What whould have gone wrong possibly as there is no rollback and commited well
rite.

First Case

090917 23:07:11	    580 Connect     root@localhost on mpcms4
		    580 Query       SHOW VARIABLES
		    580 Query       SHOW COLLATION
		    580 Query       SET character_set_results=NULL
		    580 Init DB     mpcms4
		    580 Query       SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ
		    580 Query       BEGIN
090917 23:07:19	    580 Query       Insert into tblProduct Set productID
=3220,productCategoryID='14',productSubCategoryID='41',productBrandID='1010',productGroupID='21',productStatusID='1',productCode='GIFT-ITEC-PS-STD-O',productName='SE
PHONE
STRING',productType='Accessory',rrpMarkUpType='Fixed',rrpMarkUpAmount=0,rrpMarkUpFixed=10,rrpMarkUpPercentage=0
090917 23:07:20	    580 Query       Update tblProduct Set
productCategoryID='14',productSubCategoryID='41',productBrandID='1010',productGroupID='21',productStatusID='1',productCode='GIFT-ITEC-PS-STD-O',productName='ITECH
PHONE
STRING',productType='Accessory',rrpMarkUpType='Fixed',rrpMarkUpAmount=0,rrpMarkUpFixed=10,rrpMarkUpPercentage=0
Where productID = 3220
090917 23:07:21	    580 Query       Insert into tblProduct Set productID
=3221,productCategoryID='14',productSubCategoryID='25',productBrandID='1010',productGroupID='21',productStatusID='1',productCode='GIFT-SE-PS-STD-O',productName='SE
PHONE
STRING',productType='Accessory',rrpMarkUpType='Fixed',rrpMarkUpAmount=0,rrpMarkUpFixed=10,rrpMarkUpPercentage=0
		    580 Query       COMMIT
090917 23:07:22	    580 Quit  

Second Case
090917 23:37:33	    631 Connect     root@localhost on mpcms4
		    631 Query       SHOW VARIABLES
		    631 Query       SHOW COLLATION
		    631 Query       SET character_set_results=NULL
		    631 Init DB     mpcms4
		    631 Query       SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ
		    631 Query       BEGIN
090917 23:38:04	    631 Query       Insert into tblProductGroup Set productGroupID
=819,productGroupCode='BLB2',productGroupDescription='BLB2'
090917 23:38:05	    631 Query       Insert into tblProduct Set productID
=3222,productCategoryID='6',productSubCategoryID='1',productBrandID='277',productGroupID='819',productStatusID='34',productCode='ACC-BAT-NK-BLB2-MAX',productName='MOMAX
BATTERY
BLB2',productType='Accessory',rrpMarkUpType='Fixed',rrpMarkUpAmount=0,rrpMarkUpFixed=29,rrpMarkUpPercentage=0
090917 23:38:06	    631 Query       COMMIT
090917 23:38:07	    631 Quit  

How to repeat:
Commit did not show the lines.

Sorry, but I don't get it. I see COMMIT at the end of both cases. I do not see UPDATE in
the second case. Can you, please, show the real code of your application maybe, to find
out where the real problem is.

Dear Valeriy,
             Actually let me explain my application first I have a central server with a
copy of my db in there so first the update will be run in the central copy db then there
it will store the updates into a table called tblUpdateLocal so that the same updates can
later run on my local db. So each time it will check the tblUpdateLocal if there is any
query to be run on my localdb. So it will open the connection then build the transaction.
Then for each of the query run it on my localdb and at the same time I will delete it on
my centralcopy db. Then finally I commit. So I have attached my full codes will proper
comment it looks a bit complex but I have explain to you the above flow. The funny part
is that if my codes have problem then it should not run for my other data only this two
funny cases. Thank you.

Dear Valeriy,
            I would like to add because infact I have my log file which record every
query which is update from the central db to my local. Infact even in that log it doesnt
show any error and show a sucessfull transaction. I am very surprise what would have
cause this mystery. The log for both my cases is below:

Case 1
Opening Time9/17/2009 11:07:04 PM

RUNNING SCRIPT ON LOCAL Insert into tblProduct Set productID
=3220,productCategoryID='14',productSubCategoryID='41',productBrandID='1010',productGroupID='21',productStatusID='1',productCode='GIFT-ITEC-PS-STD-O',productName='SE
PHONE
STRING',productType='Accessory',rrpMarkUpType='Fixed',rrpMarkUpAmount=0,rrpMarkUpFixed=10,rrpMarkUpPercentage=0

DELETING SCRIPT ON LOCAL Insert into tblProduct Set productID
=3220,productCategoryID='14',productSubCategoryID='41',productBrandID='1010',productGroupID='21',productStatusID='1',productCode='GIFT-ITEC-PS-STD-O',productName='SE
PHONE
STRING',productType='Accessory',rrpMarkUpType='Fixed',rrpMarkUpAmount=0,rrpMarkUpFixed=10,rrpMarkUpPercentage=0

RUNNING SCRIPT ON LOCAL Update tblProduct Set
productCategoryID='14',productSubCategoryID='41',productBrandID='1010',productGroupID='21',productStatusID='1',productCode='GIFT-ITEC-PS-STD-O',productName='ITECH
PHONE
STRING',productType='Accessory',rrpMarkUpType='Fixed',rrpMarkUpAmount=0,rrpMarkUpFixed=10,rrpMarkUpPercentage=0
Where productID = 3220

DELETING SCRIPT ON LOCAL Update tblProduct Set
productCategoryID='14',productSubCategoryID='41',productBrandID='1010',productGroupID='21',productStatusID='1',productCode='GIFT-ITEC-PS-STD-O',productName='ITECH
PHONE
STRING',productType='Accessory',rrpMarkUpType='Fixed',rrpMarkUpAmount=0,rrpMarkUpFixed=10,rrpMarkUpPercentage=0
Where productID = 3220

RUNNING SCRIPT ON LOCAL Insert into tblProduct Set productID
=3221,productCategoryID='14',productSubCategoryID='25',productBrandID='1010',productGroupID='21',productStatusID='1',productCode='GIFT-SE-PS-STD-O',productName='SE
PHONE
STRING',productType='Accessory',rrpMarkUpType='Fixed',rrpMarkUpAmount=0,rrpMarkUpFixed=10,rrpMarkUpPercentage=0

DELETING SCRIPT ON LOCAL Insert into tblProduct Set productID
=3221,productCategoryID='14',productSubCategoryID='25',productBrandID='1010',productGroupID='21',productStatusID='1',productCode='GIFT-SE-PS-STD-O',productName='SE
PHONE
STRING',productType='Accessory',rrpMarkUpType='Fixed',rrpMarkUpAmount=0,rrpMarkUpFixed=10,rrpMarkUpPercentage=0

 Closing Time9/17/2009 11:07:22 PM

Case 2

Opening Time9/17/2009 11:37:22 PM

RUNNING SCRIPT ON LOCAL Insert into tblProductGroup Set productGroupID
=819,productGroupCode='BLB2',productGroupDescription='BLB2'

DELETING SCRIPT ON LOCAL Insert into tblProductGroup Set productGroupID
=819,productGroupCode='BLB2',productGroupDescription='BLB2'

RUNNING SCRIPT ON LOCAL Insert into tblProduct Set productID
=3222,productCategoryID='6',productSubCategoryID='1',productBrandID='277',productGroupID='819',productStatusID='34',productCode='ACC-BAT-NK-BLB2-MAX',productName='MOMAX
BATTERY
BLB2',productType='Accessory',rrpMarkUpType='Fixed',rrpMarkUpAmount=0,rrpMarkUpFixed=29,rrpMarkUpPercentage=0

DELETING SCRIPT ON LOCAL Insert into tblProduct Set productID
=3222,productCategoryID='6',productSubCategoryID='1',productBrandID='277',productGroupID='819',productStatusID='34',productCode='ACC-BAT-NK-BLB2-MAX',productName='MOMAX
BATTERY
BLB2',productType='Accessory',rrpMarkUpType='Fixed',rrpMarkUpAmount=0,rrpMarkUpFixed=29,rrpMarkUpPercentage=0

 Closing Time9/17/2009 11:38:07 PM

How do you check the results of changes? Is it possible that you do it via transaction
that was opened before the changes, with default REPEATABLE READ isolation level?

Dear Valeriy,
            How I check is that I compare the number of lines in my central copy server
and local server. So when the number of lines dont tally then I try to go down and trace
where the problem where I found is this.I dont get you when you say "Is it possible that
you do it via transaction
that was opened before the changes, with default REPEATABLE READ isolation level?"
Actually now I am using REPEATABLE READ. The problem here is that I dont understand why
this case only it failed all this while it have been working well. Thank you for looking
into this problem.

Thank you for the feedback.

> How I check is that I compare the number of lines in my central copy server
and local server.

So do you check # of rows in table tblUpdateLocal on remote server and # of rows in
tables tblProduct and tblProductGroup on local server?

Please send us error logs from both server.

Also version 5.0.67 is old and many bugs were fixed since. Would be good if you can check
if problem is repeatable with current version 5.0.86.

Dear Steva,
          I have uploaded both the .err files for the central and local databases. Yes I
compare the number of row of tblProduct in central server and in local server. Thank you
is there anything else I can give you.

Thank you for the feedback.

Error logs contain no error. This means it is hard to find idea why this happens.

Please try current version 5.0.86 and if problem still exists add code which will log
warnings and errors after every statement you issue to the application you use. Please
also be sure you compare the number of rows after application is finished: no parallel
transaction uses table tblProduct when you check number of its rows.

Dear Sveta,
           I got few extra question if there was error typically what the error would be
looking like. So in this case this for redo log how about the undo log can we view them
also is it ? Typically I see this statements like this 090928 10:51:51  InnoDB: Started;
log sequence number 0 26299631 so then there is one start which show is shutdown also on
a log sequence number what does this indicitate? Another thing notice on my central error
log file have this error ? What is this error below indicating can you clear me on this ?
Will this have effect on my database ? Can you explain further when you say "log warnings
and errors after every statement you issue tothe application you use" and also "no
parallel transaction uses tabletblProduct when you check number of its rows" Thank you.

InnoDB: The log sequence number in ibdata files does not match
InnoDB: the log sequence number in the ib_logfiles!
090926 21:26:29  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...