Closed Bug 856925 Opened 13 years ago Closed 7 years ago

Binding mozIStorageBindingParams causes an error to be logged if statement executed in a transaction

Categories

(Core :: SQLite and Embedded Database Bindings, defect)

defect
Not set
normal

Tracking

()

RESOLVED INACTIVE

People

(Reporter: rnewman, Unassigned)

References

Details

(Whiteboard: [leave open])

Attachments

(2 files, 1 obsolete file)

/* Any copyright is dedicated to the Public Domain. * http://creativecommons.org/publicdomain/zero/1.0/ */ "use strict"; const {classes: Cc, interfaces: Ci, utils: Cu} = Components; do_get_profile(); Cu.import("resource://gre/modules/commonjs/sdk/core/promise.js"); Cu.import("resource://gre/modules/osfile.jsm"); Cu.import("resource://gre/modules/Sqlite.jsm"); Cu.import("resource://gre/modules/Task.jsm");Cu.import("resource://gre/modules/Services.jsm"); Cu.import("resource://gre/modules/XPCOMUtils.jsm"); XPCOMUtils.defineLazyModuleGetter(this, "FileUtils", "resource://gre/modules/FileUtils.jsm"); add_task(function test_direct() { let file = FileUtils.getFile("TmpD", ["test_direct.sqlite"]); file.createUnique(Ci.nsIFile.NORMAL_FILE_TYPE, FileUtils.PERMS_FILE); print("Opening " + file.path); let db = Services.storage.openDatabase(file); print("Opened " + db); db.executeSimpleSQL("CREATE TABLE types (id INTEGER PRIMARY KEY AUTOINCREMENT, name TEXT, UNIQUE (name))"); print("Executed setup."); let statement = db.createAsyncStatement("INSERT INTO types (name) VALUES (:name)"); let params = statement.newBindingParamsArray(); let one = params.newBindingParams(); one.bindByName("name", null); params.addParams(one); let two = params.newBindingParams(); two.bindByName("name", "bar"); params.addParams(two); print("Beginning transaction."); db.beginTransaction(); statement.bindParameters(params); let deferred = Promise.defer(); print("Executing async."); // At this point, the log will show: // WARNING: SQLite returned error code 1 , Storage will convert it // to NS_ERROR_FAILURE: file /Users/rnewman/moz/hg/services-central/ // storage/src/mozStoragePrivateHelpers.cpp, line 79 statement.executeAsync({ handleResult: function (resultSet) { }, handleError: function (error) { print("Error when executing SQL (" + error.result + "): " + error.message); print("Original error: " + error.error); errors.push(error); deferred.reject(); }, handleCompletion: function (reason) { print("Completed."); deferred.resolve(); } }); yield deferred.promise; db.commitTransaction(); statement.finalize(); deferred = Promise.defer(); db.asyncClose(function () { deferred.resolve() }); yield deferred.promise; });
Note that the query *works*... it just prints an error. The same occurs whether or not the bindings are built within the transaction, added to the statement inside or outside the transaction. The only thing that makes the error go away is *not using a transaction*. See Bug 833965 for more.
beginTransaction and commitTransaction are synchronous API's and should not be mixed with async connection usage. Thanks to the use of generators, the code here is deterministic but not particularly a good idea. executeAsync automatically wraps async requests issued to it in a transaction if there is more than one effective statement to be executed. You are binding two sets of parameters, so this logic applies. The net result is you are trying to create a transaction inside of a transaction, which is an error in SQLite. It's a bit of a mozStorage deficiency that it always wants to wrap everything in a transaction. If you want to do manual statement mangement right now you need to executeAsync statements one by one. Thunderbird's global database does this because it wants to manually control transactions and can't agglomerate the requests into a single big batch. It would obviously be great if that limitation were resolved.
(In reply to Andrew Sutherland (:asuth) from comment #2) Thank you for the input! > beginTransaction and commitTransaction are synchronous API's and should not > be mixed with async connection usage. Thanks to the use of generators, the > code here is deterministic but not particularly a good idea. What if we were to executeAsync("BEGIN DEFERRED TRANSACTION") instead? This is a synthetic example; the real code (in Sqlite.jsm, see Bug 833965) uses executeAsync to control transactions. Same nested transaction problem? > executeAsync automatically wraps async requests issued to it in a > transaction if there is more than one effective statement to be executed. > You are binding two sets of parameters, so this logic applies. Are you suggesting that the use of a bindings array is precisely equivalent to calling executeAsync on each set of params, but within the same implicit transaction? We do see a noticeable speed improvement through doing this, so something seems to be better… > It's a bit of a mozStorage deficiency that it always wants to wrap > everything in a transaction. If you want to do manual statement mangement > right now you need to executeAsync statements one by one. Thunderbird's > global database does this because it wants to manually control transactions > and can't agglomerate the requests into a single big batch. It would > obviously be great if that limitation were resolved. Interesting. We were under the impression that the automatic transaction mode was just the reflection of sqlite's feature -- that is, if you don't start a transaction, one is created for you. If that's not the case, then yeah, it's a significant deficiency. We very, very much want control over transaction extent in Sqlite.jsm and FHR. What's the next step to make that available?
Flags: needinfo?(mak77)
(In reply to Richard Newman [:rnewman] from comment #3) > > beginTransaction and commitTransaction are synchronous API's and should not > > be mixed with async connection usage. Thanks to the use of generators, the > > code here is deterministic but not particularly a good idea. > > What if we were to executeAsync("BEGIN DEFERRED TRANSACTION") instead? I verified this: it doesn't make a difference.
Attached patch Proposed patch. v1 (obsolete) — Splinter Review
The attached patch avoids both creating and committing a transaction if the async executor decides that a transaction should be used, but one already exists. This is essentially equivalent to transaction coalescing. (Note that it doesn't make sense to create a transaction if one already exists, so this patch makes a lot of sense in isolation, let alone in context!) Sqlite.jsm tests pass -- all three versions -- without the mentioned SQLite error once this change is applied.
Assignee: nobody → rnewman
Status: NEW → ASSIGNED
Attachment #732586 - Flags: review?(mak77)
Line 582 now reads: // commit it when we're done, which would defeat the point. -- typo in the attachment. Thanks Nick for spotting!
OS: Mac OS X → All
Hardware: x86 → All
(In reply to Richard Newman [:rnewman] from comment #3) > Interesting. We were under the impression that the automatic transaction > mode was just the reflection of sqlite's feature -- that is, if you don't > start a transaction, one is created for you. If that's not the case, then > yeah, it's a significant deficiency. Both are true. If you are not in a transaction and you execute a write statement, SQLite will create an implicit transaction for that statement. Though, when executing 2 statements it would create and commit 2 separate implicit transactions, while the optimal situation is that there's just one. Thus why Storage tries to be wise, by wrapping multiple implicit transactions into one. This happens in a couple situations iirc: 1. if you bound multiple params to a single write statement, you are basically executing multiple write statements (the same but multiple times), thus Storage tries to wrap that into a transaction. 2. if you are using mozIStorageConnection.executeAsync and you pass to it more than one write statement then again it tries to wrap those into a transaction.
Flags: needinfo?(mak77)
(In reply to Marco Bonardo [:mak] from comment #7) > Thus why Storage tries to be wise, by wrapping multiple implicit > transactions into one. > This happens in a couple situations iirc: > 1. if you bound multiple params to a single write statement, you are > basically executing multiple write statements (the same but multiple times), > thus Storage tries to wrap that into a transaction. > 2. if you are using mozIStorageConnection.executeAsync and you pass to it > more than one write statement then again it tries to wrap those into a > transaction. Yeah, I figured this out, mostly. The issue (IMO) is that Storage isn't smart enough to figure out that I already began a transaction, and just starts one anyway. That doesn't make sense, either from a practical standpoint or according to sqlite, which reports an error. The minimal patch I provided simply checks whether one is underway, and avoids starting another if so.
Comment on attachment 732586 [details] [diff] [review] Proposed patch. v1 Review of attachment 732586 [details] [diff] [review]: ----------------------------------------------------------------- you want to add a dedicated test to test_asyncStatementExecution_transaction.cpp that verifies there is no transaction if one is created and committed externally ::: storage/src/mozStorageAsyncStatementExecution.cpp @@ +582,5 @@ > + // commit in when we're done, which would defeat the point. > + bool inProgress; > + nsresult rv = mConnection->GetTransactionInProgress(&inProgress); > + NS_ENSURE_SUCCESS(rv, rv); > + if (!inProgress) { At first glance this doesn't look not much thread-safe, the main-thread could close or open a transaction just after this check, making it pointless. Maybe in this if we could just store a needTransaction bool, when executing the for loop we already acquire mDBMutex, at that point we could check needTransaction and transactionInProgress, open the transaction if needed, and proceed as usual. The downside is we will lock the mutex a brief more, but should be minor overhead since we are about to write that is a quite expensive operation.
Attachment #732586 - Flags: review?(mak77) → review-
Since it seems like the patch assumes use of it, I want to really emphasize that: db.beginTransaction(); is starting a transaction on the main thread synchronously. This will cause the main thread to acquire the connection mutex which can cause it to block on the ongoing activities of the async thread, perform synchronous I/O, etc. Because we already have this existing footgun API, I think any efforts to improve the transaction handling on the async thread should stay far away from directly using it or using something with a similar function signature because of the potential for confusion. Really, I question the need for such a convenience helper for asynchronous purposes only. The function makes sense in a synchronous C++ world where use of the helper that uses the function call means you get RAII that can automatically commit or rollback the transaction based on control flow/scope. But for asynchronous operations and JS code, you will not know if you got an error or back during the existing control-flow, and JS has no real RAII/finalizers (although you could try and hackjob it with js-ctypes) even if you are being clever with generators. I would suggest that the most reasonable course of action is to make the pure async connection API either use one of two modes: 1) automatic transaction management, so people changing their code to the new pure async won't experience horrible regressions. 2) an opt-in mode where transaction management is entirely up to the caller. They can just issue 'BEGIN' and 'COMMIT' statements on their own, especially if they're using a JSM helper that can help reduce the complexity of building an array of async statements to send on the connection.
(In reply to Andrew Sutherland (:asuth) from comment #10) > Since it seems like the patch assumes use of it, I want to really emphasize > that: > > db.beginTransaction(); > > is starting a transaction on the main thread synchronously. The patch does not assume so. It doesn't call it, nor is the use of beginTransaction required to demonstrate the error. > 2) an opt-in mode where transaction management is entirely up to the caller. > They can just issue 'BEGIN' and 'COMMIT' statements on their own, especially > if they're using a JSM helper that can help reduce the complexity of > building an array of async statements to send on the connection. This is exactly what we do, and it's exactly what causes Storage to flail and do the wrong thing (namely blindly try to create nested transactions), which is exactly what this patch is attempting to fix.
Of interest, mozStorageTransaction talks a lot about transactions already being in progress. Perhaps this is a more fundamental bug in that class?
OK, here's what happens. We call executeAsync with a bindings array. That results in AsyncExecuteStatements being invoked. statementsNeedTransaction() is true, so the mozStorageAsyncStatementExecution instantiates a mozStorageTransaction. Its constructor calls mConnection->BeginTransactionAs(TRANSACTION_IMMEDIATE). That calls ExecuteSimpleSQL(NS_LITERAL_CSTRING("BEGIN IMMEDIATE")), which causes SQLite to log: 0:03.40 WARNING: SQLite returned error code 1 , Storage will convert it to NS_ERROR_FAILURE: file /Users/rnewman/moz/hg/services-central/storage/src/mozStoragePrivateH I don't see sqlite3_get_autocommit called *anywhere* in /storage/, which means we are definitely not checking for whether a query initiated a transaction. That alone might account for the error. Alternatively, this might be synchronously executing, which presumably shouldn't be happening. What's interesting about this is that a test I just wrote in C++ works perfectly, logging: YYY: Connection::ExecuteAsync dispatching. XXX: AsyncExecuteStatements YYY: Running AsyncExecuteStatements. YYY: Connection::ExecuteAsync dispatching. XXX: AsyncExecuteStatements YYY: Running AsyncExecuteStatements. YYY: Connection::ExecuteAsync dispatching. XXX: AsyncExecuteStatements YYY: Running AsyncExecuteStatements. while my test from JS -- which should follow the same call paths -- hits these: 0:03.07 XXX: AsyncExecuteStatements 0:03.07 YYY: Running AsyncExecuteStatements. 0:03.07 YYY: Making new mozStorageTransaction. 0:03.07 YYY: mozStorageTransaction 0:03.07 YYY: mozStorageTransaction has a connection. 0:03.07 YYY: A 0:03.07 WARNING: SQLite returned error code 1 , Storage will convert it to NS_ERROR_FAILURE: file /Users/rnewman/moz/hg/services-central/storage/src/mozStoragePrivateHelpers.cpp, line 79 0:03.07 YYY: B 0:03.07 YYY: mozStorageTransaction::Commit. 0:03.07 YYY: mozStorageTransaction::Commit: transaction not ours, ignore. 0:03.07 Completed. 0:03.07 XXX: AsyncExecuteStatements 0:03.07 YYY: Running AsyncExecuteStatements. I'm now digging into the discrepancy.
Ah, my C++ test didn't actually cause statementsNeedTransaction to return true. When I fix that, and add appropriate fflush calls, I get the error logging, and mozStorageTransaction doesn't commit because the transaction failed to be established. This latter behavior is why all of our tests continue to pass, even with that error being logged.
This also means that a test which detects this failure needs to either (a) spot a *failed* transaction begin, or (b) poke at mozStorageTransaction to detect this scenario. Code that just begins transactions asynchronously and then tries to do work just gets a log line and the test passes.
(In reply to Marco Bonardo [:mak] from comment #9) > you want to add a dedicated test to > test_asyncStatementExecution_transaction.cpp that verifies there is no > transaction if one is created and committed externally I have put together a very thorough test. Unfortunately it can't test this issue. The problem is that it's the act of creating a new transaction that fails, and that takes place within the ExecuteAsync call, with none of the actors visible from outside. * The sqlite error code is not reported through sqlite3_errcode. * convertResultCode swallows after logging. * The entire mozStorageAsyncStatementExecution deal, including mozStorageHelper, is unavailable outside the context of the execution. * There's no error reporting channel built-in already. * I guess you'd r- any attempt to add error count tracking to the connection itself. So I give up: I can make sure everything *works*, but that's not the same as writing a test that fails before my patch. > At first glance this doesn't look not much thread-safe, the main-thread > could close or open a transaction just after this check, making it pointless. That could happen now, though, right? Right now we *always* try to begin a transaction, which sometimes causes an error to be recorded. This way we *rarely* try to begin an unnecessary transaction. You're right that there's a risk of us finding that there is a transaction, electing not to start one, and then it closing before we run. But that could also happen now: we make a mozStorageTransaction and it fails horribly because a transaction is running (exactly this bug), and then we *ignore it* and go right ahead with the execution. In other words: no matter how this fails, it's no worse than now. > Maybe in this if we could just store a needTransaction bool, when executing > the for loop we already acquire mDBMutex, at that point we could check > needTransaction and transactionInProgress, open the transaction if needed, > and proceed as usual. The downside is we will lock the mutex a brief more, > but should be minor overhead since we are about to write that is a quite > expensive operation. I just tried this, and hit the deadlock detection. We're holding the mutex, hand off to mozStorageTransaction, which calls back to BeginTransactionAs, which tries to grab sharedDBMutex. Perhaps I'm not understanding how the locking works here. For my forthcoming patch I'm going to skip solving this, unless you can point me in the right direction. It seems like BeginTransactionAs might need to die.
Note that the `needsTransaction` bit is present so you can mentally translate it inside the loop. If we elect to ignore that for now, I'll elide that.
Attachment #732586 - Attachment is obsolete: true
Attachment #733726 - Flags: review?(mak77)
Sqlite.jsm tests that manually exercise this functionality.
Attachment #733727 - Flags: review?(gps)
Basically, SQLite.jsm cannot use the beginTransaction API, since it's synchronous, so it directly uses BEGIN/COMMIT/ROLLBACK, by using a Task it can implement a sort of "finalized" transaction. Though this way mTransactionInProgress is not updated, since it's updated by BeginTransactionAs but we don't go through it. Inside that transaction we executeAsync something that tries to create a transaction, this invokes BeginTransactionAs, that checks mTransactionInProgress, that unfortunately is out-of-sync, so it's false even if a transaction is in progress. This also means our transactionInProgress API is basically broken. I agree with Andrew that the beginTransaction, transactionInProgress and such are a poor API and we should avoid bringing it with us. But it's not the problem here, SQLite.jsm way to handle transaction is nicer through the use of Task. What if we'd find a better way to keep mTransactionInProgress up-to-date? SQLite has sqlite3_commit_hook and sqlite3_rollback_hook that we could use to set it to false, unfortunately it doesn't have a sqlite3_transaction_hook, though I think we may ask for it to be added (that would probably also allow us to write a test for this, registering the hook in the test). This should both fix our sucky legacy API and solve this issue since then mTransactionInProgress would be something we could rely on, and the cpp transaction RAII would work as expected. (In reply to Richard Newman [:rnewman] from comment #16) > I have put together a very thorough test. Unfortunately it can't test this > issue. yeah I figured later, I thought we could detect begin of a transaction, but we can't. > > At first glance this doesn't look not much thread-safe, the main-thread > > could close or open a transaction just after this check, making it pointless. > > That could happen now, though, right? Well, something different, what happens right now is this bug. Your change makes things better sure, but doesn't solve this bug, or at least not 100%. The fact it's no worse than now doesn't mean it's a solution :( We could take it as a short-term fix if we first agree on a long-term fix. Andrew, do you think the transaction_hook could be a valid solution, even for future transaction tracking needs?
Flags: needinfo?(bugmail)
Ideally we could even move everything to SAVEPOINTs, if not that they don't allow IMMEDIATE transactions... though my understanding is that we use immediate transactions due to the existence of 2 concurrent threads, that means a single-threaded connection (like the pure async one) could be fine with SAVEPOINTs. SAVEPOINTs can be nested.
I just found sqlite_begin_hook had been added along with sqlite_commit_hook in 2003, but has never made a final version.
(In reply to Marco Bonardo [:mak] from comment #19) > Inside that transaction we executeAsync something that tries to create a > transaction, this invokes BeginTransactionAs, that checks > mTransactionInProgress, that unfortunately is out-of-sync, so it's false > even if a transaction is in progress. This also means our > transactionInProgress API is basically broken. Indeed. You'll notice the fix I put in is to directly query whether autocommit is set, which essentially offloads the tracking of in-progress transactions to the database itself. I'm not sure if this is enough to replace mTransactionInProgress; I even considered being more invasive and replacing line 44 in mozStorageHelper, but elected to not go any further than I already have, considering I simply wanted to get rid of a logged error and get Bug 856170 landed :) > What if we'd find a better way to keep mTransactionInProgress up-to-date? I thought about that, but as you found we don't have a documented begin hook. If you can get one added next week, or find a different way, then sure… :D > SQLite has sqlite3_commit_hook and sqlite3_rollback_hook that we could use > to set it to false, unfortunately it doesn't have a > sqlite3_transaction_hook, though I think we may ask for it to be added (that > would probably also allow us to write a test for this, registering the hook > in the test). Indeed (assuming it fires on attempts, not just success; the error is from a failed attempt). > This should both fix our sucky legacy API and solve this issue since then > mTransactionInProgress would be something we could rely on, and the cpp > transaction RAII would work as expected. Yup. > Well, something different, what happens right now is this bug. Your change > makes things better sure, but doesn't solve this bug, or at least not 100%. > The fact it's no worse than now doesn't mean it's a solution :( > We could take it as a short-term fix if we first agree on a long-term fix. Agreed that it's not a solution, but it does mean I can land bulk inserts in Sqlite.jsm and use them in FHR without scary errors in the log. The right solution seems to involve reworking how Storage manages transactions, which is a bigger patch than I'd like to sign up for on this timeframe. That solution could be tracking from sqlite hooks, or using the native autocommit flag instead, or as simple as exposing an async beginTransaction call that sets the storage flag (acknowledging that some users will just executeAsync("BEGIN TRANSACTION") and screw everything up). I'd be open to any of these things.
Comment on attachment 733727 [details] [diff] [review] Additional tests that no longer cause an error to be printed. v1 Review of attachment 733727 [details] [diff] [review]: ----------------------------------------------------------------- Please document the purpose of this test (it's not obvious from just the source)! Other than that and some trailing whitespace, LGTM. ::: toolkit/modules/tests/xpcshell/test_sqlite.js @@ +17,5 @@ > // To spin the event loop in test. > Cu.import("resource://services-common/async.js"); > > +XPCOMUtils.defineLazyModuleGetter(this, "FileUtils", > + "resource://gre/modules/FileUtils.jsm"); Nit: No need to do this lazy foo inside tests.
Attachment #733727 - Flags: review?(gps) → review+
I sent a mail to the SQLite team to ask whether we may expect a sqlite3_begin_hook API or there are good reasons to not have one. The answer may help deciding what to do.
Their suggestion is to try using sqlite3_get_autocommit, if that is not enough an hook may be added at our request. Now, you already used it in AsyncExecuteStatements::Run, but I think could make more sense to try injecting it directly into BeginTransactionAs and GetTransactionInProgress. mTransactionInProgress could still be used to track whether a transaction has been started through BeginTransactionAs to couple Commit/RollbackTransaction calls. I'd suggest filing a separate dependency for this. I don't think it will be a big patch.
Blocks: 860357
(In reply to Marco Bonardo [:mak] from comment #25) > Now, you already used it in AsyncExecuteStatements::Run, but I think could > make more sense to try injecting it directly into BeginTransactionAs and > GetTransactionInProgress. > mTransactionInProgress could still be used to track whether a transaction > has been started through BeginTransactionAs to couple > Commit/RollbackTransaction calls. Is this something you'd like me to do, or would you prefer to crank it out yourself? Would you like to land this patch in the mean time, because I'm unlikely to get to it for a couple of weeks? > I'd suggest filing a separate dependency for this. I don't think it will be > a big patch. Done (not sure which way you want the dependency to point).
(In reply to Richard Newman [:rnewman] from comment #26) > Is this something you'd like me to do, or would you prefer to crank it out > yourself? Hard question, matter of available time. > Would you like to land this patch in the mean time, because I'm unlikely to > get to it for a couple of weeks? Actually, if I got this correctly the only drawback of the current situation is that Storage throws a warning, but everything keeps working as expected, that means it's not something we need "yesterday", we should be able to wait a bit for a proper fix, I think?
No longer blocks: 860357
Depends on: 860357
(In reply to Marco Bonardo [:mak] from comment #27) > > Would you like to land this patch in the mean time, because I'm unlikely to > > get to it for a couple of weeks? > > Actually, if I got this correctly the only drawback of the current situation > is that Storage throws a warning, but everything keeps working as expected, > that means it's not something we need "yesterday", we should be able to wait > a bit for a proper fix, I think? Correct, assuming that incurring a sqlite error by attempting to begin a transaction is nearly free. I don't know if that's true.
Whiteboard: [leave open]
(In reply to Richard Newman [:rnewman] from comment #28) > Correct, assuming that incurring a sqlite error by attempting to begin a > transaction is nearly free. I don't know if that's true. I don't think any cost would be interesting compared to the cost of the write operation that is about to happen. Yes, I think it's ignorable for now.
Comment on attachment 733726 [details] [diff] [review] Proposed patch. v2 I think I can remove this request for now, until we have a plan for the dependency
Attachment #733726 - Flags: review?(mak77)
Whiteboard: [leave open] → [leave open][Async]
mak: do you want to set some tracking or needinfo flag to make sure this doesn't go stale?
better in bug 860357
Flags: needinfo?(bugmail)
mak, can we resolve this?
Attachment #733726 - Flags: checkin+
Attachment #733727 - Flags: checkin+
what landed is a workaround, we need the dependency for a proper fix. probably should split the bug apart.
Whiteboard: [leave open][Async] → [leave open]
Assignee: rnewman → nobody
Status: ASSIGNED → NEW
Per policy at https://wiki.mozilla.org/Bug_Triage/Projects/Bug_Handling/Bug_Husbandry#Inactive_Bugs. If this bug is not an enhancement request or a bug not present in a supported release of Firefox, then it may be reopened.
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → INACTIVE
Product: Toolkit → Core
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: