739697 - (NS_ERROR_FAILURE) [mozIStorageConnection.beginTransaction] Stack trace: resource:///components/nsFormHistory.js:253 < FormStore_remove()

Status: RESOLVED FIXED

(Toolkit :: Form Manager, defect)

Description

[Joe Drew (not getting mail)]

Attachment: error log

My Aurora profile has a continuous sync error, seemingly in the forms data engine. I've attached the error log.

Comment 1

[Richard Newman [:rnewman]]

Sounds like your profile is screwed…

Comment 2

[Matthew N. [:MattN]]

Does form history still work in forms and the search box?  Try adding, selecting, and deleting entries.

Comment 3

[Joe Drew (not getting mail)]

Yeah, I can operate on my form history just fine, it seems.

Comment 6

[Matthew N. [:MattN]]

(In reply to Joe Drew (:JOEDREW!) from comment #3)
> Yeah, I can operate on my form history just fine, it seems.

Joe or other reporters, can you set browser.formfill.debug = true and then follow these steps:
1) Clear your error console
2) Go to a form with form history entries.
3) Type some text to get a list of entries.
4) Select an entry and delete it. See https://support.mozilla.org/en-US/kb/Form-autocomplete#w_deleting-individual-form-entries
5) Type some other text in the same field to overwrite the result cache.
6) Type the same text from #3 and see if the deleted result shows up.
7) Check the error console for warning or errors related to form history aka. Satchel and paste them here.

Comment 7

[Matthew N. [:MattN]]

Possibly related to bug 725881 which added a moz_deleted_formhistory table.

Comment 8

[Matthew N. [:MattN]]

(In reply to Matthew N. [:MattN] from comment #6)
> 7) Check the error console for warning or errors related to form history
> aka. Satchel and paste them here.

To be clear, they probably wont' be reported as "Errors" or "Warnings" in the console, they will mostly show as "Messages".

Comment 9

[Joe Drew (not getting mail)]

Mostly, there are no errors from that sequence of events. However, I got some seemingly sync-related errors afterwards:

FormHistory: entryExists for searchbar-history=arm branch instructions
FormHistory: entryExists: id=6871
FormHistory: entryExists for searchbar-history=eglInitialize
FormHistory: entryExists: id=6872
FormHistory: addEntry for searchbar-history=hyatt regency sf
FormHistory: Creating new statement for query: INSERT INTO moz_formhistory (fieldname, value, timesUsed, firstUsed, lastUsed, guid) VALUES (:fieldname, :value, :timesUsed, :firstUsed, :lastUsed, :guid)
FormHistory: removeEntry for firstName=Joe
FormHistory: removeEntry failed: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [mozIStorageConnection.beginTransaction]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: resource:///components/nsFormHistory.js :: <TOP_LEVEL> :: line 253"  data: no]

Sync then notices the failure and errors out.

Comment 10

[Matthew N. [:MattN]]

I think this is because bug 725881 made more APIs use transactions and according to MDN[1], nested transactions are not supported: "The database engine does not support nested transactions, so attempting to start a transaction when one is already active will throw an exception."

It seems that the problem is that Sync is beginning a transaction for formhistory.sqlite[2] but then removeEntry begins its own transaction at nsFormHistory.js:253 since bug 725881 landed.

[1] https://developer.mozilla.org/en/Storage#Transactions
[2] https://mxr.mozilla.org/mozilla-central/source/services/sync/modules/engines/forms.js?rev=13a57f89f8cc&force=1#211

Comment 11

[Richard Newman [:rnewman]]

moveToDeletedTable is ifdeffed on only for Android, which is the only platform on which we use the deleted items table.

Perhaps the transaction handling for those newly transactional methods ought to be conditional also, or check dbConnection.transactionInProgress…

Comment 12

[Joe Drew (not getting mail)]

This, unfortunately, has now progressed to my main profile! It appeared as I was in the middle of using Firefox.

Comment 13

[Richard Newman [:rnewman]]

(In reply to Joe Drew (:JOEDREW!) from comment #12)
> This, unfortunately, has now progressed to my main profile! It appeared as I
> was in the middle of using Firefox.

Yes, this will reliably affect any Firefox 13+ profile that attempts to sync a form history deletion. It's not going to be an intermittent thing.

Comment 14

[Matthew N. [:MattN]]

I'll make a patch for #ifdef ANDROID now since bug 566746 is around the corner which will clean some of these problems up.

Comment 15

[Matthew N. [:MattN]]

Attachment: #ifdef ANDROID around transaction code which isn't necessary for non-android in the specific cases for Sync

#ifdef ANDROID for removeEntry and removeAllEntries

The transaction doesn't do us any good for removeEntry outside of Android anyways.

Comment 16

[Richard Newman [:rnewman]]

Comment on attachment 612753 [details] [diff] [review]
#ifdef ANDROID around transaction code which isn't necessary for non-android in the specific cases for Sync

Review of attachment 612753 [details] [diff] [review]:
-----------------------------------------------------------------

Call this a conditional review: it looks good to me if this is the approach zpao wants to take. I don't own this code.

(Note that your patch needs bug headers: https://developer.mozilla.org/en/Mercurial_FAQ#How_can_I_generate_a_patch_for_somebody_else_to_check-in_for_me.3F )

My opinion gently leans towards making this code more robust in general, rather than ifdeffing around the issue: that is, if it can't support nested transactions, make it aware of outstanding transactions and dynamically behave appropriately. Otherwise we're eventually going to hit exactly the same problem in some other calling code that doesn't expect a transaction to be started here. This should be fairly straightforward, and makes the module strictly more flexible.

zpao?

Comment 17

[Paul O'Shannessy [:zpao] (not bugmail, email directly)]

Comment on attachment 612753 [details] [diff] [review]
#ifdef ANDROID around transaction code which isn't necessary for non-android in the specific cases for Sync

Review of attachment 612753 [details] [diff] [review]:
-----------------------------------------------------------------

I know you & dolske talked about just doing this, but I think Richard is right. It's just as easy to check connection.transactionInProgress at the beginning of these methods & just not dong any transaction work if true.

The end goal is to just get async form history done & in where this gets automagically handled, but we're not there yet.

(insert grumble about not exposing dbconnection to take away footguns)

Comment 18

[Matthew N. [:MattN]]

Attachment: v.2 check for existing transaction

I put the access of transactionInProgress in the try block in case the connection is null.  Let me know if you prefer the declaration and assignment on the same line.

(In reply to Richard Newman [:rnewman] from comment #16)
> (Note that your patch needs bug headers:
> https://developer.mozilla.org/en/
> Mercurial_FAQ#How_can_I_generate_a_patch_for_somebody_else_to_check-
> in_for_me.3F )

I have commit access so don't use checkin-needed and there isn't an HG command that I know to export the patch with 8 lines of context while keeping 3 lines for MQ.  

> My opinion gently leans towards making this code more robust in general,
> rather than ifdeffing around the issue: that is, if it can't support nested
> transactions, make it aware of outstanding transactions and dynamically
> behave appropriately. Otherwise we're eventually going to hit exactly the
> same problem in some other calling code that doesn't expect a transaction to
> be started here. This should be fairly straightforward, and makes the module
> strictly more flexible.

Sure, but we will hopefully be able to get rid of external access to DBConnection once bug 566746 lands.

Comment 19

[Richard Newman [:rnewman]]

(In reply to Matthew N. [:MattN] from comment #18)

> I have commit access so don't use checkin-needed …

It's nice when the patch that gets r+ is the same as the one that lands (e.g., for uplift approval), regardless of whether you're able to check it in yourself.

> and there isn't an HG
> command that I know to export the patch with 8 lines of context while
> keeping 3 lines for MQ.  

I use these:

[diff]
git = 1
unified = 8
showfunc = true

[defaults]
diff=-U8
qdiff=-U8
qnew=-U
qseries=-sv

You can replace the qdiff line with `qdiff=-U3`, which *should* (I haven't tested) make the patch file itself (the one we care about) contain 8 lines of context, but include only 3 lines when using qdiff -- or vice versa if that's what you care about. So long as you upload with 8!

Try it out and let me know how it goes!

> Sure, but we will hopefully be able to get rid of external access to
> DBConnection once bug 566746 lands.

I can't believe that bug's still going! :D

Making the forms API async doesn't eliminate the need for performance-aware callers to manually manage transactions. There is likely to still be work required to address that before Sync can avoid getting elbow-deep in database prodding.

(Sync adds form items fifty at a time, because it might be inserting three or four thousand, and sixty write transactions are way better than three thousand.)

Comment 20

[Matthew N. [:MattN]]

(In reply to Richard Newman [:rnewman] from comment #19)
> [diff]
> git = 1
> unified = 8

From when I last tested, it's this `unified = 8` line above that is used for MQ and for export so you can't have one diff from the other.

> Making the forms API async doesn't eliminate the need for performance-aware
> callers to manually manage transactions. There is likely to still be work
> required to address that before Sync can avoid getting elbow-deep in
> database prodding.

Yeah, I realize that. It's not the async aspect of the bug, it's the new API which Sync requested.  If there is something more that is needed they can possibly be included in that bug.

Comment 21

[Paul O'Shannessy [:zpao] (not bugmail, email directly)]

Comment on attachment 613006 [details] [diff] [review]
v.2 check for existing transaction

(In reply to Matthew N. [:MattN] from comment #18)
> Created attachment 613006 [details] [diff] [review]
> v.2 check for existing transaction
> 
> I put the access of transactionInProgress in the try block in case the
> connection is null.  Let me know if you prefer the declaration and
> assignment on the same line.

If the connection is null/that can throw, then we're in trouble. transactionInProgress will be falsey after the try/catch/finally where we then would attempt to commit. We've made assumptions about the connection in the past so let's just move it out of the try block. If you think we need to handle that error separately (rethrow or whatever), then do what you think is appropriate before the try block.

Comment 22

[Matthew N. [:MattN]]

Attachment: v.2b check for existing transaction outside of try block

(In reply to Paul O'Shannessy [:zpao] from comment #21)
> Comment on attachment 613006 [details] [diff] [review]
> v.2 check for existing transaction
> 
> (In reply to Matthew N. [:MattN] from comment #18)
> > Created attachment 613006 [details] [diff] [review]
> > v.2 check for existing transaction
> > 
> > I put the access of transactionInProgress in the try block in case the
> > connection is null.  Let me know if you prefer the declaration and
> > assignment on the same line.
> 
> If the connection is null/that can throw, then we're in trouble.
> transactionInProgress will be falsey after the try/catch/finally where we
> then would attempt to commit. (In reply to Paul O'Shannessy [:zpao] from comment #21)
> Comment on attachment 613006 [details] [diff] [review]
> v.2 check for existing transaction
> 
> (In reply to Matthew N. [:MattN] from comment #18)
> > Created attachment 613006 [details] [diff] [review]
> > v.2 check for existing transaction
> > 
> > I put the access of transactionInProgress in the try block in case the
> > connection is null.  Let me know if you prefer the declaration and
> > assignment on the same line.
> 
> If the connection is null/that can throw, then we're in trouble.
> transactionInProgress will be falsey after the try/catch/finally where we
> then would attempt to commit.

Actually, the catch block is rethrowing the exception in all of these cases so this isn't actually an issue from what I can tell.

I'm attaching a patch that does what you requested anyways since both options seem fine to me. Review whichever one you prefer.

Comment 23

[Paul O'Shannessy [:zpao] (not bugmail, email directly)]

(In reply to Matthew N. [:MattN] from comment #22)
> Actually, the catch block is rethrowing the exception in all of these cases
> so this isn't actually an issue from what I can tell.

Oh true. Not sure what I was thinking... either I missed the rethrow or I was thinking the commit was inside the finally block...

Comment 24

[Matthew N. [:MattN]]

Comment on attachment 613006 [details] [diff] [review]
v.2 check for existing transaction

[Approval Request Comment]
Regression caused by (bug #): bug 725881
User impact if declined: User will see a persistent sync notification bar at the bottom of their browser if a form history entry was deleted and needs to sync.
Testing completed (on m-c, etc.): m-c
Risk to taking this patch (and alternatives if risky): Low risk of breaking form history deletion in a different way although we do have unit/mochitests for that.
String changes made by this patch: None

Comment 25

[Alex Keybl [:akeybl]]

Comment on attachment 613006 [details] [diff] [review]
v.2 check for existing transaction

[Triage Comment]
Approving for central since this is something we'd want to track for release. We'll check back in a couple of days for aurora approval.

Comment 26

[Matthew N. [:MattN]]

Thanks.

https://hg.mozilla.org/integration/mozilla-inbound/rev/9d11d469890f

Comment 27

[(no longer active)]

https://hg.mozilla.org/mozilla-central/rev/9d11d469890f

Comment 28

[Alex Keybl [:akeybl]]

Comment on attachment 613006 [details] [diff] [review]
v.2 check for existing transaction

Approving for Aurora 13 now that this has had a day of bake time on m-c.

Comment 29

[Matthew N. [:MattN]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/5baf8061c697

Comment 30

[u279076]

Can someone who was able to reproduce this bug please verify the fix in Firefox 13.0b3 and latest-mozilla-aurora?