| Bug #47427 | Why commit but not in my database | ||
|---|---|---|---|
| Submitted: | 18 Sep 2009 2:23 | Modified: | 3 Feb 2010 18:40 |
| Reporter: | newbie Shai | Email Updates: | |
| Status: | Not a Bug | Impact on me: | |
| Category: | MySQL Server: InnoDB storage engine | Severity: | S1 (Critical) |
| Version: | 5.0.67 | OS: | Windows |
| Assigned to: | CPU Architecture: | Any | |
| Tags: | Commit not inserting the value | ||
[18 Sep 2009 3:47]
Valeriy Kravchuk
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.
[18 Sep 2009 17:33]
newbie Shai
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.
[19 Sep 2009 18:05]
newbie Shai
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
[21 Sep 2009 4:14]
Valeriy Kravchuk
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?
[21 Sep 2009 12:14]
newbie Shai
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.
[29 Sep 2009 7:04]
Sveta Smirnova
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.
[29 Sep 2009 19:00]
newbie Shai
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.
[3 Oct 2009 8:44]
Sveta Smirnova
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.
[3 Oct 2009 17:14]
newbie Shai
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...
[29 Jan 2010 8:10]
Sveta Smirnova
Thank you for the feedback. > I got few extra question if there was error typically what the error would be looking like. It will look like [ERROR] ..... > So in this case this for redo log how about the undo log can we view them also is it ? Sorry, I don't understand this question. Please explain. Thought if you ask about a way to examine InnoDB log files there is no utility for doing this. > 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? This means database was not shutdown properly, so InnoDB has to recover data from its logs. > 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 ? Yes, I did. But after this error central server was properly restarted several times. This should not affect this case unless you started to get wrong results immediately after the crash and never before. > Can you explain further when you say "log warnings > and errors after every statement you issue tothe application you use" Add mysql_error() and mysql_warning_count() calls to your application after every mysql_real_query() call. I used C API function names. See API you use for exact function names. > and also "no > parallel transaction uses tabletblProduct when you check number of its rows" Thank you. You don't experience following scenario. Assuming there are 2 clinets: c1 and c2 c1> begin; c1> select * from tabletblProduct; c2> begin; c2> delete from tabletblProduct where ... c1> select count() from tabletblProduct; In this case c1 can get wrong results for count() query.
[29 Jan 2010 8:13]
Sveta Smirnova
Additional note to previous comment: "In this case c1 can get wrong results for count() query." means wrong results for purpose to be sure number of rows is identical on both servers after script was run..
[29 Jan 2010 17:00]
newbie Shai
Dear Sveta,
Thank you for your explanation given. So you have answered me that we cannot view both the redo and undo logs. Where is the undo logs kept and when it will be activated. About your statement "This means database was not shutdown properly, so InnoDB has to recover data from its
logs." What causes the database not to be shutdown properly. When it is recovering data is it from the redo logs or undo logs ? I am using C# so is that using the system exception to capture the errors is it?
[1 Feb 2010 6:19]
Sveta Smirnova
Thank you for the feedback. > What causes the database not to be shutdown properly. Crash of the mysqld, host operating system or `kill -9` command. > When it is recovering data is it from the redo logs or undo logs ? When it starts. > I am using C# so is that using the system exception to capture the errors is it? Should be either same functions which I described in comment "[29 Jan 9:10] Sveta Smirnova" or, if you are using Connector/NET, functions of c/NET interface. See documentation.
[3 Feb 2010 15:53]
newbie Shai
Dear Sveta,
So as soon the system start both the redo and undo logs will start is it? Is both the logs are in the ibdata files is it? The crash of the mysqld, can be many reason right? What is `kill -9`? Thank you.
[3 Feb 2010 18:40]
Sveta Smirnova
Dear newbie Shai, We're sorry, but the bug system is not the appropriate forum for asking help on using MySQL products. Latest comments are not related to the bug at all. And most likely your problem is not result of bug in MySQL code. Support on using our products is available both free in our forums at http://forums.mysql.com/ and for a reasonable fee direct from our skilled support engineers at http://www.mysql.com/support/ Thank you for your interest in MySQL.
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.