Closed Bug 1067054 Opened 10 years ago Closed 10 years ago

Tons of startup-spam: "WARNING: SQLite returned error code 1 , Storage will convert it to NS_ERROR_FAILURE: file mozStoragePrivateHelpers.cpp" & "WARNING: Unable to create a transaction for async execution.: file mozStorageAsyncStatementExecution.cpp"

Categories

(Toolkit :: Storage, defect)

defect
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla40
Tracking Status
firefox40 --- fixed

People

(Reporter: dholbert, Assigned: chiragbhatia2006, Mentored)

References

Details

(Keywords: regression, Whiteboard: [good first bug][lang=cpp])

Attachments

(2 files, 3 obsolete files)

In my debug build today, when starting up, I'm getting 38 lines of the warning-spam, consisting of 4 lines of this: { WARNING: SQLite returned error code 1 , Storage will convert it to NS_ERROR_FAILURE: file /mozilla/storage/src/mozStoragePrivateHelpers.cpp, line 78 } followed by one line of this: { WARNING: Unable to create a transaction for async execution.: file /scratch/work/builds/mozilla-central/mozilla-central.13-11-22.16-03/mozilla/storage/src/mozStorageAsyncStatementExecution.cpp, line 596 } (and then two straggling warnings of the first type at the end) I don't recall noticing this before, so I suspect it's a recent regression. Based on hg log for storage/src, I'm guessing bug 1047811 might be involved (that looks like the only recent change there). Tentatively marking as blocking that bug, though I haven't confirmed that.
Attached file log of all the warnings (deleted) —
The first warning is expected cause in many cases we don't get a proper sqlite error and blindly converting to ns_error_failure may be confusing. Though, I think SQLITE_ERROR (value 1) is so generic that a generic conversion to NS_ERROR_FAILURE is fine. We should instead report any other error that is not tracked and not SQLITE_ERROR. The second warning is bogus, we should use getAutocommit to check if a transaction exists and only if it doesn't exists issue a warning, it's indeed expected that the transaction fails to be created if one is already active. So, I think we can avoid both.
Component: Places → Storage
Blocks: fx-noise
Keywords: regression
Mentor: mak77
Whiteboard: [good next bug][lang=cpp]
This should not be that hard, and would bring huge benefit when reading test logs. Let's make it more visible.
Whiteboard: [good next bug][lang=cpp] → [good first bug][lang=cpp]
Hi mak, I'd like to work on this bug. Can you please point the line numbers where the change is to be made? I'm guessing the line numbers mentioned in Comment 3 are outdated because of the file being updated over the time.
Flags: needinfo?(mak77)
The lines in comment 3 are still correct. The first one points to the first warning, we need to condition that warning by using NS_WARN_IF instead of NS_WARNING, using rc != SQLITE_ERROR. Indeed we want to warn only if we convert other kind of Sqlite errors to a generic error, since SQLITE_ERROR is the most generic error already, there's no reason to warn. The second one points to the condition that causes the second warning 595 else { 596 NS_WARNING("Unable to create a transaction for async execution."); Here we should warn only if we were unable to create a transaction due to Sqlite errors, not if it failed cause there is already a transaction ongoing. It should be possible to change the if to if (statementsNeedTransaction() && !mConnection->getAutoCommit()) AutoCommit mode is active outside of transactions, so if getAutoCommit is false we are already inside a transaction and we cannot instantiate a new one.
Flags: needinfo?(mak77)
I tried the code changes you mentioned above and they worked, i.e. the error messages no longer appear. Can you please assign the bug to me so that I can attach the patch? Also, do I need to test if these error messages appear in the scenarios when they are supposed to? If yes, can you please tell me steps to do so?
Flags: needinfo?(mak77)
In both cases it's hard to give reliable steps to hit the warnings, cause they are intended to happen in rare internal failure cases (for example SQLITE_INERNAL, SQLITE_NOTFOUND and such).
Assignee: nobody → chiragbhatia2006
Status: NEW → ASSIGNED
Flags: needinfo?(mak77)
Attached patch 1067054.patch (obsolete) (deleted) — Splinter Review
Let me know if anything needs to be changed in this.
Attachment #8586187 - Flags: review?(mak77)
Comment on attachment 8586187 [details] [diff] [review] 1067054.patch Review of attachment 8586187 [details] [diff] [review]: ----------------------------------------------------------------- ::: storage/src/mozStorageAsyncStatementExecution.cpp @@ +585,5 @@ > } > if (mState == CANCELED) > return notifyComplete(); > > + if (statementsNeedTransaction() && !mConnection->getAutoCommit()) { I just figured out that I inverted the condition in comment 6. If getAutoCommit() returns true, a transaction is NOT ongoing, and thus we CAN begin one. Since here we try to begin a transaction, we want autoCommit to be true. ::: storage/src/mozStoragePrivateHelpers.cpp @@ +74,5 @@ > nsAutoCString message; > message.AppendLiteral("SQLite returned error code "); > message.AppendInt(rc); > message.AppendLiteral(" , Storage will convert it to NS_ERROR_FAILURE"); > + NS_WARN_IF(rc != SQLITE_ERROR); you added the condition, but not the message, you still needs to use message.get() to print the warning message we built. Unfortunately NS_WARN_IF doesn't support a message, so we must use NS_WARN_IF_FALSE(condition, message); clearly you need to invert the condition.
Attachment #8586187 - Flags: review?(mak77)
Attached patch 1067054.patch (obsolete) (deleted) — Splinter Review
I've made the changes that you've mentioned in the above comment and re-tested, the warning messages do not appear. Hope I got it right. Let me know if you can think of anything else we might have to add / change.
Attachment #8586187 - Attachment is obsolete: true
Attachment #8586894 - Flags: review?(mak77)
Comment on attachment 8586894 [details] [diff] [review] 1067054.patch Review of attachment 8586894 [details] [diff] [review]: ----------------------------------------------------------------- yes now it looks good, I'll push this to Try.
Attachment #8586894 - Flags: review?(mak77) → review+
Sorry but the patch doesn't compile. which command did you use to build it? You should rebuild with ./mach build storage library The problem is that getAutoCommit doesn't exist, it's getAutocommit http://mxr.mozilla.org/mozilla-central/source/storage/src/mozStorageConnection.h#126
Keywords: checkin-needed
Attached patch 1067054.patch (obsolete) (deleted) — Splinter Review
You're right, sorry about that. ./mach build storage library doesn't work for me (I don't have a directory named library in my mozilla-central? Should there be?) I just did a ./mach build to do the entire build and found the compile error, and fixed it like you said. Here's the corrected patch
Attachment #8586894 - Attachment is obsolete: true
Attachment #8587573 - Flags: review?(mak77)
./mach build storage toolkit/library (but maybe the latter is built automatically, don't recall off-hand)
Comment on attachment 8587573 [details] [diff] [review] 1067054.patch Review of attachment 8587573 [details] [diff] [review]: ----------------------------------------------------------------- https://treeherder.mozilla.org/#/jobs?repo=try&revision=8cca9fa03d01
Attachment #8587573 - Flags: review?(mak77) → review+
Keywords: checkin-needed
("./mach build binaries" is the supported foolproof way to do a quick rebuild, if all you're changing is .cpp files and .h files. That should always work, and if it doesn't, it's a bug. You can also target specific directories and maybe shave a second off of your build time, but it's rarely worth it because the command will be longer and you'll be less sure that you actually did it right.)
looks like this is asserting in getAutocommit when running extensions/cookie/test/unit/test_eviction.js cause mDBConn is null (db is closed). I must look into that.
Keywords: checkin-needed
Flags: needinfo?(mak77)
Attached patch 1067054.patch (deleted) — Splinter Review
The assert is sort of bogus, or better, it was valid until now. Async statements can run after mDBConn has been nullified, while the threads are merged. so, this just removes the assert and avoids an eventual crash.
Attachment #8587573 - Attachment is obsolete: true
Flags: needinfo?(mak77)
https://treeherder.mozilla.org/#/jobs?repo=try&revision=d7f12438d2bf The os x failures don't look related to me, I actually couldn't figure them out... Maybe my trychooser is outdated? Dunno, but it seems a timeout in libicu that I didn't touch...
Keywords: checkin-needed
Keywords: checkin-needed
Whiteboard: [good first bug][lang=cpp] → [good first bug][lang=cpp][fixed-in-fx-team]
Status: ASSIGNED → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
Whiteboard: [good first bug][lang=cpp][fixed-in-fx-team] → [good first bug][lang=cpp]
Target Milestone: --- → mozilla40
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: