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"

RESOLVED FIXED in Firefox 40

Status

()

Toolkit
Storage
RESOLVED FIXED
3 years ago
3 years ago

People

(Reporter: dholbert, Assigned: Chirag Bhatia, Mentored)

Tracking

(Blocks: 1 bug, {regression})

Trunk
mozilla40
regression
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox40 fixed)

Details

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

Attachments

(2 attachments, 3 obsolete attachments)

(Reporter)

Description

3 years ago
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.
(Reporter)

Comment 1

3 years ago
Created attachment 8489056 [details]
log of all the warnings
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
so basically we should exclude rc == 1 here http://mxr.mozilla.org/mozilla-central/source/storage/src/mozStoragePrivateHelpers.cpp#74

and use mConnection->getAutocommit here http://mxr.mozilla.org/mozilla-central/source/storage/src/mozStorageAsyncStatementExecution.cpp#589

Updated

3 years ago
Blocks: 341986
Keywords: regression
Mentor: mak77@bonardo.net
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]
(Assignee)

Comment 5

3 years ago
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)
(Assignee)

Comment 7

3 years ago
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)
(Assignee)

Comment 9

3 years ago
Created attachment 8586187 [details] [diff] [review]
1067054.patch

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)
(Assignee)

Comment 11

3 years ago
Created attachment 8586894 [details] [diff] [review]
1067054.patch

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+
https://treeherder.mozilla.org/#/jobs?repo=try&revision=56bef64c6f00
Keywords: checkin-needed
OS: Linux → All
Hardware: x86_64 → All
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
(Assignee)

Comment 15

3 years ago
Created attachment 8587573 [details] [diff] [review]
1067054.patch

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
(Reporter)

Comment 18

3 years ago
("./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)
Created attachment 8591049 [details] [diff] [review]
1067054.patch

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
https://hg.mozilla.org/integration/fx-team/rev/d5df101900d9
Keywords: checkin-needed
Whiteboard: [good first bug][lang=cpp] → [good first bug][lang=cpp][fixed-in-fx-team]
https://hg.mozilla.org/mozilla-central/rev/d5df101900d9
Status: ASSIGNED → RESOLVED
Last Resolved: 3 years ago
status-firefox40: --- → fixed
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.