The default bug view has changed. See this FAQ.

Expose when queries are being inefficient in debug builds

RESOLVED FIXED in mozilla1.9.2a1

Status

()

Toolkit
Storage
RESOLVED FIXED
8 years ago
8 years ago

People

(Reporter: sdwilsh, Assigned: sdwilsh)

Tracking

Trunk
mozilla1.9.2a1
Points:
---
Dependency tree / graph
Bug Flags:
wanted1.9.1 ?
in-testsuite -
in-litmus -

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(2 attachments, 2 obsolete attachments)

(Assignee)

Description

8 years ago
sqlite3_stmt_status can tell us the number of sort operations that have occurred. A non-zero value in this counter may indicate an opportunity to improvement performance through careful use of indices.  If this value is non-zero, we should dump out a warning to the console indicating the statement and that it might be better optimized.

See http://www.sqlite.org/c3ref/stmt_status.html and http://www.sqlite.org/c3ref/c_stmtstatus_fullscan_step.html
(Assignee)

Updated

8 years ago
Whiteboard: [good first bug]
(Assignee)

Comment 1

8 years ago
Created attachment 365974 [details] [diff] [review]
v1.0

...like so

Output looks something like this:
WARNING: 1 sort operation has occurred for the SQL statement 'SELECT b.id FROM moz_bookmarks b JOIN ( SELECT id FROM moz_places_temp WHERE url = ?1 UNION ALL SELECT id FROM moz_places WHERE url = ?1 AND +id NOT IN (SELECT id FROM moz_places_temp) ) AS h ON b.fk = h.id WHERE b.type = ?2 ORDER BY MAX(IFNULL(b.lastModified, 0), b.dateAdded) DESC, b.id DESC'.  This may indicate an opportunity to improve performance through the careful use of indexes.: file /Code/moz/central/mozilla/storage/src/mozStorageStatement.cpp, line 464
Assignee: nobody → sdwilsh
Status: NEW → ASSIGNED
Attachment #365974 - Flags: review?(bugmail)
(Assignee)

Updated

8 years ago
Whiteboard: [good first bug] → [needs review asuth]
Target Milestone: --- → mozilla1.9.2a1
I'm a little wary of the warning in the documentation that things may change in the future. I hope this wouldn't impact our ability to upgrade sqlite on a security branch.

The documentation is also pretty unclear. Will it still warn even if you are using indexes to help speed things along? If so then I think this might be more noise than use.
(Assignee)

Comment 3

8 years ago
(In reply to comment #2)
> I'm a little wary of the warning in the documentation that things may change in
> the future. I hope this wouldn't impact our ability to upgrade sqlite on a
> security branch.
Since this is debug only code, I don't think it will impact us.  And if it did, we have a few options available still that wouldn't hurt.

> The documentation is also pretty unclear. Will it still warn even if you are
> using indexes to help speed things along? If so then I think this might be more
> noise than use.
The count would be zero in this case, so it will not warn.  Using an index to sort isn't considered a sort operation.  For SQLite, using a sort operation means getting all the data, and then sorting based on some column.  An index doesn't need to get all the data before sorting - it does it as you get results.
Comment on attachment 365974 [details] [diff] [review]
v1.0

This works nicely for synchronous execution, although perhaps sad for things that directly finalize without resetting.  Maybe AsyncExecute::ExecuteAndProcessStatement wants to do this too?
Attachment #365974 - Flags: review?(bugmail) → review+
(Assignee)

Comment 5

8 years ago
Created attachment 366328 [details] [diff] [review]
v1.1

(In reply to comment #4)
> This works nicely for synchronous execution, although perhaps sad for things
> that directly finalize without resetting.  Maybe
> AsyncExecute::ExecuteAndProcessStatement wants to do this too?
good idea.  went and did some refactoring while I was at it.
Attachment #365974 - Attachment is obsolete: true
Attachment #366328 - Flags: review?(bugmail)
(Assignee)

Updated

8 years ago
Depends on: 482276
Attachment #366328 - Attachment is patch: true
Attachment #366328 - Attachment mime type: application/octet-stream → text/plain

Updated

8 years ago
Blocks: 482346

Updated

8 years ago
Blocks: 482351

Updated

8 years ago
Blocks: 482353
Attachment #366328 - Flags: review?(bugmail) → review+
Comment on attachment 366328 [details] [diff] [review]
v1.1

Yes, it definitely points the finger at a gloda async query now.

>diff --git a/nsprpub/configure b/nsprpub/configure
>-DEFS=`sed -f conftest.defs confdefs.h | tr '\012' ' ' | tr '\015' ' '`
>+DEFS=`sed -f conftest.defs confdefs.h | tr '\012' ' '`

Witty comment involving how you probably didn't mean to change nspr this in the patch, and if you did, it probably should go in another patch...

>diff --git a/storage/src/mozStoragePrivateHelpers.cpp b/storage
>+#include "sqlite3.h"
>+#include "nsString.h"
>+
>+#include "mozStoragePrivateHelpers.h"

Maybe include nsError.h too?  Clearly, it builds, and nsString is unlikely to stop pulling it, so it doesn't matter.  Not sure what the party line is on this.
(Assignee)

Comment 7

8 years ago
(In reply to comment #6)
> Witty comment involving how you probably didn't mean to change nspr this in the
> patch, and if you did, it probably should go in another patch...
No idea how that got in there...

> Maybe include nsError.h too?  Clearly, it builds, and nsString is unlikely to
> stop pulling it, so it doesn't matter.  Not sure what the party line is on
> this.
Yeah, I'll include it.  Not sure why it's building, but not inclined to figure it out either!
(Assignee)

Updated

8 years ago
Flags: in-testsuite-
Flags: in-litmus-
Whiteboard: [needs review asuth]
(Assignee)

Comment 8

8 years ago
http://hg.mozilla.org/mozilla-central/rev/6c56947c095f

Filed bug 483002 as a followup to make an API to expose this information to debugger-like applications.
(Assignee)

Updated

8 years ago
Status: ASSIGNED → RESOLVED
Last Resolved: 8 years ago
Resolution: --- → FIXED
Could these warnings be made opt-in with an environment variable or something?
(Assignee)

Comment 10

8 years ago
(In reply to comment #9)
> Could these warnings be made opt-in with an environment variable or something?
I posted to dev-platform last week about this very bug and nobody complained then.  Fact is, these issues are real bugs and should be fixed.

Comment 11

8 years ago
This is the most annoying thing ever. Make it opt-in, please.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Opt-in how?  PR_LOG?  Log4Moz (bug 451283)?  conditional on -DDEBUG_STORAGE instead of -DDEBUG?  environment variable magic?
PR_LOG, with FORCE_PR_LOG so it's available in optimized builds as well.
(Assignee)

Comment 14

8 years ago
Created attachment 367802 [details] [diff] [review]
v2.0

This changes our behavior in a number of ways:
1) allow a statement to annotate itself so that it will not warn.  This can be accomplished by adding a comment to the SQL:
/* do not warn (bug
The idea is to require a bug to be on file for the issue.
2) do not dump out the SQL string, but dump out the address of the statement pointer instead.  These are stable, and if you want to get the SQL of the statement, you have to use NSPR logging.

Of course, this may not even be deemed acceptable, but that will be discussed in today's meeting during the roundtable.
Attachment #367802 - Flags: review?(bugmail)
(Assignee)

Updated

8 years ago
Whiteboard: [needs review asuth]
Comment on attachment 367802 [details] [diff] [review]
v2.0

Perhaps the NS_WARNING could mention that PR_LOG needs to be turned on for mozStorage?  Not mentioning the actual statement that's the problem and not telling you how to find out really cuts down on the utility of the spam in the first place.

I'd argue that a better course of action for the warning might be to only spit out the warning (with the full SQL!) once and then suppress it after that.  The message might even be made more gaudy, and slightly more useful by including a link to a devmo page documenting how one can 1) banninate the message, and 2) solve the message.
The PR_LOG should keep doing its thing though.

I'm fine with this solution too, but that's arguably only because I'm used to layout spamming all over the place for Thunderbird.

nb: Assuming a full 8 characters are used for the %p part, the minimum warning at this point is 158 characters in length.
Attachment #367802 - Flags: review?(bugmail) → review+
Whiteboard: [needs review asuth] → [has review]
(Assignee)

Comment 16

8 years ago
Created attachment 368560 [details] [diff] [review]
v2.1

Shortens the warning and points folks to https://developer.mozilla.org/En/Storage/Warnings

We can use this page for more things in the future.
Attachment #367802 - Attachment is obsolete: true
(Assignee)

Updated

8 years ago
Whiteboard: [has review] → [can land]
(Assignee)

Comment 17

8 years ago
http://hg.mozilla.org/mozilla-central/rev/a809eae39341
Status: REOPENED → RESOLVED
Last Resolved: 8 years ago8 years ago
Resolution: --- → FIXED
Whiteboard: [can land]

Updated

8 years ago
Blocks: 487594

Updated

8 years ago
Blocks: 487781

Updated

8 years ago
Blocks: 487787

Updated

8 years ago
Blocks: 487789
(Assignee)

Comment 18

8 years ago
I apparently landed this on 1.9.1.  I don't recall ever doing it, but pushlog blames me.  Weird.  I've backed it out now.
Flags: wanted1.9.1?
You need to log in before you can comment on or make changes to this bug.