On 01/26/2014 08:24 AM, Tomas Vondra wrote:
Hi!

On 25.1.2014 22:21, Heikki Linnakangas wrote:
Attached is a new version of the patch set, with those bugs fixed.

I've done a bunch of tests with all the 4 patches applied, and it seems
to work now. I've done tests with various conditions (AND/OR, number of
words, number of conditions) and I so far I did not get any crashes,
infinite loops or anything like that.

I've also compared the results to 9.3 - by dumping the database and
running the same set of queries on both machines, and indeed I got 100%
match.

I also did some performance tests, and that's when I started to worry.

For example, I generated and ran 1000 queries that look like this:

   SELECT id FROM messages
    WHERE body_tsvector @@ to_tsquery('english','(header & 53 & 32 &
useful & dropped)')
    ORDER BY ts_rank(body_tsvector, to_tsquery('english','(header & 53 &
32 & useful & dropped)')) DESC;

i.e. in this case the query always was 5 words connected by AND. This
query is a pretty common pattern for fulltext search - sort by a list of
words and give me the best ranked results.

On 9.3, the script was running for ~23 seconds, on patched HEAD it was
~40. It's perfectly reproducible, I've repeated the test several times
with exactly the same results. The test is CPU bound, there's no I/O
activity at all. I got the same results with more queries (~100k).

Attached is a simple chart with x-axis used for durations measured on
9.3.2, y-axis used for durations measured on patched HEAD. It's obvious
a vast majority of queries is up to 2x slower - that's pretty obvious
from the chart.

Only about 50 queries are faster on HEAD, and >700 queries are more than
50% slower on HEAD (i.e. if the query took 100ms on 9.3, it takes >150ms
on HEAD).

Typically, the EXPLAIN ANALYZE looks something like this (on 9.3):

      http://explain.depesz.com/s/5tv

and on HEAD (same query):

      http://explain.depesz.com/s/1lI

Clearly the main difference is in the "Bitmap Index Scan" which takes
60ms on 9.3 and 120ms on HEAD.

On 9.3 the "perf top" looks like this:

     34.79%  postgres                 [.] gingetbitmap
     28.96%  postgres                 [.] ginCompareItemPointers
      9.36%  postgres                 [.] TS_execute
      5.36%  postgres                 [.] check_stack_depth
      3.57%  postgres                 [.] FunctionCall8Coll

while on 9.4 it looks like this:

     28.20%  postgres                 [.] gingetbitmap
     21.17%  postgres                 [.] TS_execute
      8.08%  postgres                 [.] check_stack_depth
      7.11%  postgres                 [.] FunctionCall8Coll
      4.34%  postgres                 [.] shimTriConsistentFn

Not sure how to interpret that, though. For example where did the
ginCompareItemPointers go? I suspect it's thanks to inlining, and that
it might be related to the performance decrease. Or maybe not.

Yeah, inlining makes it disappear from the profile, and spreads that time to the functions calling it.

The profile tells us that the consistent function is called a lot more than before. That is expected - with the fast scan feature, we're calling consistent not only for potential matches, but also to refute TIDs based on just a few entries matching. If that's effective, it allows us to skip many TIDs and avoid consistent calls, which compensates, but if it's not effective, it's just overhead.

I would actually expect it to be fairly effective for that query, so that's a bit surprising. I added counters to see where the calls are coming from, and it seems that about 80% of the calls are actually coming from this little the feature I explained earlier:

In addition to that, I'm using the ternary consistent function to check
if minItem is a match, even if we haven't loaded all the entries yet.
That's less important, but I think for something like "rare1 | (rare2 &
frequent)" it might be useful. It would allow us to skip fetching
'frequent', when we already know that 'rare1' matches for the current
item. I'm not sure if that's worth the cycles, but it seemed like an
obvious thing to do, now that we have the ternary consistent function.

So, that clearly isn't worth the cycles :-). At least not with an expensive consistent function; it might be worthwhile if we pre-build the truth-table, or cache the results of the consistent function.

Attached is a quick patch to remove that, on top of all the other patches, if you want to test the effect.

- Heikki
diff --git a/src/backend/access/gin/ginget.c b/src/backend/access/gin/ginget.c
index f2f9dc6..76a70a0 100644
--- a/src/backend/access/gin/ginget.c
+++ b/src/backend/access/gin/ginget.c
@@ -895,6 +895,25 @@ keyGetItem(GinState *ginstate, MemoryContext tempCtx, GinScanKey key,
 								GinItemPointerGetBlockNumber(&minItem));
 
 		/*
+		 * We might not have loaded all the entry streams for this TID. We
+		 * could call the consistent function, passing MAYBE for those entries,
+		 * to see if it can decide if this TID matches based on the information
+		 * we have. But if the consistent-function is expensive, and cannot
+		 * in fact decide with partial information, that could be a big loss.
+		 * So, loop back to load the missing entries, before calling the
+		 * consistent function.
+		 */
+		if (minUnknown != -1)
+		{
+			for (i = minUnknown; i < key->nentries; i++)
+			{
+				entry = key->scanEntry[i];
+				if (ginCompareItemPointers(&entry->curItem, &advancePast) <= 0)
+					entryGetItem(ginstate, entry, advancePast);
+			}
+		}
+
+		/*
 		 * Lossy-page entries pose a problem, since we don't know the correct
 		 * entryRes state to pass to the consistentFn, and we also don't know
 		 * what its combining logic will be (could be AND, OR, or even NOT).
@@ -996,18 +1015,6 @@ keyGetItem(GinState *ginstate, MemoryContext tempCtx, GinScanKey key,
 				break;
 
 			case GIN_MAYBE:
-				/*
-				 * The consistent function cannot decide with the information
-				 * we've got. If there are any "unknown" sources left, advance
-				 * one of them and try again, in the hope that it can decide
-				 * with the extra information.
-				 */
-				if (minUnknown != -1)
-				{
-					entry = key->scanEntry[minUnknown];
-					entryGetItem(ginstate, entry, advancePast);
-					continue;
-				}
 				key->curItemMatches = true;
 				key->recheckCurItem = true;
 				break;
-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Reply via email to