Slow queries: SQL indexes not used

Bug #632363 reported by Mikkel Kamstrup Erlandsen
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Zeitgeist Framework
Fix Released
High
Markus Korn

Bug Description

THE PROBLEM:
I am seeing query times around 200ms (and 150ms with my latest performance tweak in trunk), which surprised me as quite slow since my queries where quite simple. I had expected times around 1-2ms.

Reading up on the sqlite documentation I see that the queries we generate are pretty far from optimized in an sqlite world [1]. The case is that when ever you use an OR sqlite will no longer use an index. Thus this query is NOT using the indexes:

  SELECT * FROM event WHERE interpretation=1 OR interpretation=2

But if we rewrite it using IN instead the indexes will be used:

  SELECT * FROM event WHERE interpretation IN (1, 2)

This also explains the case where Michal where seeing tremendously slow query times when searching for a big range of mimetypes.

Looking in _zeitgeist.engine.sql.WhereClause.add_text_condition() I am also pretty sure we are not using the indexes for prefix queries (eg file://home/*).

THE SOLUTION
I *definitely* don't think we should panic and feverishly start rewriting our query compilation. Here's what I propose:

 1) Implement an envvar ZEITGEIST_DEBUG_QUERY_PLANS which will spit out all our SQL calls and the query plans for each of our calls. The query plan will tell us how the db is queried and which indexes are used if any. The query plan is obtained by prefixing the SQL statement with EXPLAIN QUERY PLAN.

 2) Collect some useful intelligence with this new tool, and generally learn more about how we can optimize sqlite queries. A big question here is how the event_view VIEW impacts the query plan.

 3) Write a new template -> SQL compilation engine that generates SQL optimized for sqlite. We can actually be quite clever about grouping our OR statements into IN clauses - but it will be tricky to get right.

NOTE: That this doesn't imply any change in the public API or event template system. That would be the wrong solution imho. Our current API is nice and simple by my standards. Let's keep it that way.

[1]: See fx the section "Using Indexes To Speed Searching" in http://www.sqlite.org/vdbe.html

Related branches

Revision history for this message
Seif Lotfy (seif) wrote : Re: [Bug 632363] [NEW] Slow queries: SQL indexes not used
Download full text (4.8 KiB)

My concern is which time frame we should take to solve this issue... How
important is it for your work?

On Tue, Sep 7, 2010 at 2:21 PM, Mikkel Kamstrup Erlandsen <
<email address hidden>> wrote:

> Public bug reported:
>
> THE PROBLEM:
> I am seeing query times around 200ms (and 150ms with my latest performance
> tweak in trunk), which surprised me as quite slow since my queries where
> quite simple. I had expected times around 1-2ms.
>
> Reading up on the sqlite documentation I see that the queries we
> generate are pretty far from optimized in an sqlite world [1]. The case
> is that when ever you use an OR sqlite will no longer use an index. Thus
> this query is NOT using the indexes:
>
> SELECT * FROM event WHERE interpretation=1 OR interpretation=2
>
> But if we rewrite it using IN instead the indexes will be used:
>
> SELECT * FROM event WHERE interpretation IN (1, 2)
>
> This also explains the case where Michal where seeing tremendously slow
> query times when searching for a big range of mimetypes.
>
> Looking in _zeitgeist.engine.sql.WhereClause.add_text_condition() I am
> also pretty sure we are not using the indexes for prefix queries (eg
> file://home/*).
>
>
> THE SOLUTION
> I *definitely* don't think we should panic and feverishly start rewriting
> our query compilation. Here's what I propose:
>
> 1) Implement an envvar ZEITGEIST_DEBUG_QUERY_PLANS which will spit out
> all our SQL calls and the query plans for each of our calls. The query
> plan will tell us how the db is queried and which indexes are used if
> any. The query plan is obtained by prefixing the SQL statement with
> EXPLAIN QUERY PLAN.
>
> 2) Collect some useful intelligence with this new tool, and generally
> learn more about how we can optimize sqlite queries. A big question here
> is how the event_view VIEW impacts the query plan.
>
> 3) Write a new template -> SQL compilation engine that generates SQL
> optimized for sqlite. We can actually be quite clever about grouping our
> OR statements into IN clauses - but it will be tricky to get right.
>
> NOTE: That this doesn't imply any change in the public API or event
> template system. That would be the wrong solution imho. Our current API
> is nice and simple by my standards. Let's keep it that way.
>
> [1]: See fx the section "Using Indexes To Speed Searching" in
> http://www.sqlite.org/vdbe.html
>
> ** Affects: zeitgeist
> Importance: Undecided
> Status: New
>
> --
> Slow queries: SQL indexes not used
> https://bugs.launchpad.net/bugs/632363
> You received this bug notification because you are subscribed to The
> Zeitgeist Project.
>
> Status in Zeitgeist Framework: New
>
> Bug description:
> THE PROBLEM:
> I am seeing query times around 200ms (and 150ms with my latest performance
> tweak in trunk), which surprised me as quite slow since my queries where
> quite simple. I had expected times around 1-2ms.
>
> Reading up on the sqlite documentation I see that the queries we generate
> are pretty far from optimized in an sqlite world [1]. The case is that when
> ever you use an OR sqlite will no longer use an index. Thus this query is
> NOT using the indexes:
>
> SELECT * FROM event WHERE inte...

Read more...

Revision history for this message
Markus Korn (thekorn) wrote :
Changed in zeitgeist:
milestone: none → 0.6
Seif Lotfy (seif)
Changed in zeitgeist:
milestone: 0.6 → 0.7
Revision history for this message
Mikkel Kamstrup Erlandsen (kamstrup) wrote :

The document Markus points to seems to indicate that my simple OR query above would indeed be optimized to use the index. However I am still pretty convinced that we are not using the indexes in our own queries, given the speeds I see.

Revision history for this message
Seif Lotfy (seif) wrote :

I am trying to find out where we should start. Since the "OR" conditions appear when we have more than one event template. This means we need to handle the issues in _build_sql_from_event_templates in main.py by somehow decomposing the event components.

Until now we build sql template code for EACH event independently. Which makes IMHO this issue is more complex than I thought. The above examples require us to have 2 event templates where only the interpretations are different, however what if several event properties are different?

Revision history for this message
Seif Lotfy (seif) wrote :

OK I did some ugly printing to the statements lp:~zeitgeist/+junk/explain-queries
just run it and watch the statement and the explanations get printed...

http://pastebin.com/FL44gbSY

Revision history for this message
Mikkel Kamstrup Erlandsen (kamstrup) wrote :

Attached branch lp:~zeitgeist/zeitgeist/explain-logs that implements part 1) of my battle plan above. Based off Seif's work from his previous comment

Seif Lotfy (seif)
Changed in zeitgeist:
status: New → Confirmed
Revision history for this message
Mikkel Kamstrup Erlandsen (kamstrup) wrote :

Sorry, for not keeping this bug alive.

Just for any one interested - the status is that we must now use the tools we implemented: logging and ZEITGEIST_DEBUG_QUERY_PLANS, to analyze a few of the slow queries and understand *exactly* why they are slow.

Given a few samples of this, we can come up with a plan to mitigate that

Revision history for this message
Markus Korn (thekorn) wrote :

I've just filed bug 672965 for one class of slow queries

Revision history for this message
Markus Korn (thekorn) wrote :

Bug 673394 describes anopther class of slow queries

Revision history for this message
Markus Korn (thekorn) wrote :
Revision history for this message
Siegfried Gevatter (rainct) wrote :

Is this still a problem or have all instances been fixed by now?

Seif Lotfy (seif)
Changed in zeitgeist:
milestone: 0.7.0 → none
Seif Lotfy (seif)
Changed in zeitgeist:
milestone: none → 0.8.0
Revision history for this message
Seif Lotfy (seif) wrote :

I think we re-introduced this issue with the current trunk iteration...

Here is a sample period for a normal search

Trunk:

[2011-04-09 23:23:05,702] - DEBUG - zeitgeist.engine - Found 30 events IDs in 0.299371s
[2011-04-09 23:29:08,587] - DEBUG - zeitgeist.engine - Found 30 events IDs in 0.300896
[2011-04-09 23:29:31,936] - DEBUG - zeitgeist.engine - Found 30 events IDs in 0.293639s

Zeitgeist 0.7.1:

[2011-04-09 23:27:32,714] - DEBUG - zeitgeist.engine - Found 30 events IDs in 0.010847s
[2011-04-09 23:27:46,554] - DEBUG - zeitgeist.engine - Found 30 events IDs in 0.011603s
[2011-04-09 23:27:59,541] - DEBUG - zeitgeist.engine - Found 30 events IDs in 0.012207s

Revision history for this message
Seif Lotfy (seif) wrote :

Its more or less 30 times slower now

Changed in zeitgeist:
importance: Undecided → High
Revision history for this message
Seif Lotfy (seif) wrote : Re: [Bug 632363] Re: Slow queries: SQL indexes not used

I am pretty sure the problem occurred because we added 2 new columns
event.origin and event.subj_id_current

@thekorn can you look at that if possible

Revision history for this message
Seif Lotfy (seif) wrote :

It also could be related to the new storage columns in the view :)

Revision history for this message
Seif Lotfy (seif) wrote :

Seems like my DB was missing ALL the index tables.
It works fine now...
I will close this bug for now, feel free to re-open in case you think it could be optimized even more...

Changed in zeitgeist:
status: Confirmed → Fix Committed
assignee: nobody → Markus Korn (thekorn)
Seif Lotfy (seif)
Changed in zeitgeist:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.