Bug #6098

[API] slow search? SQL query

Added by Ward Vandewege over 4 years ago. Updated over 4 years ago.

Status:
Resolved
Priority:
Normal
Assigned To:
Category:
API
Target version:
Start date:
05/26/2015
Due date:
% Done:

100%

Estimated time:
(Total: 0.00 h)
Story points:
1.0

Description

explain analyze SELECT COUNT(DISTINCT "pipeline_instances"."id") FROM "pipeline_instances"  WHERE (pipeline_instances.uuid in ('qr1hi-tpzed-w68kvgin92qp9gs','qr1hi-tpzed-anonymouspublic') OR pipeline_instances.owner_uuid in ('qr1hi-tpzed-w68kvgin92qp9gs','qr1hi-tpzed-anonymouspublic','qr1hi-j7d0g-xcq63k14iwywimi','qr1hi-j7d0g-fffffffffffffff','qr1hi-j7d0g-it30l961gq3t0oi','qr1hi-j7d0g-rluyd6zowuj1zre','qr1hi-j7d0g-anonymouspublic','qr1hi-j7d0g-662ij1pcw6bj8uj','qr1hi-j7d0g-ls7mn9ilxiwvep6','qr1hi-j7d0g-key0mqeqlvhz7v7','qr1hi-j7d0g-2hth2gzle63muo6','qr1hi-j7d0g-gytictj8fzr9jfh','qr1hi-j7d0g-25wprjygblp9z2f','qr1hi-j7d0g-ziejtm5kaik7ndl','qr1hi-j7d0g-a45rn6qhjszct1d','qr1hi-j7d0g-7o66z9uq8mkgqun','qr1hi-j7d0g-iodpr5gc65cp4t0','qr1hi-j7d0g-550ma2g4nlx5ri6','qr1hi-j7d0g-gsw7n4d2g3mx1dj','qr1hi-j7d0g-fpyx8sz1lkdvcaq','qr1hi-j7d0g-l1emsbyyx6wyjdh','qr1hi-j7d0g-45zjb0b4n6cpzxa','qr1hi-j7d0g-834hs5rnunpn6y6','qr1hi-j7d0g-up6qgpqz5ie2vfq','qr1hi-j7d0g-u7zg1qdaowykd8d','qr1hi-j7d0g-mm1t3d3mmkh7n2u','qr1hi-j7d0g-k40t93v1njk9gcz','qr1hi-j7d0g-anonymouspublic','qr1hi-j7d0g-2ak9yjmy5u0hw6z','qr1hi-j7d0g-jrzr18w1nqr5326','qr1hi-j7d0g-anonymouspublic','qr1hi-j7d0g-662ij1pcw6bj8uj','qr1hi-j7d0g-ls7mn9ilxiwvep6','qr1hi-j7d0g-key0mqeqlvhz7v7','qr1hi-j7d0g-2hth2gzle63muo6','qr1hi-j7d0g-gytictj8fzr9jfh','qr1hi-j7d0g-25wprjygblp9z2f','qr1hi-j7d0g-ziejtm5kaik7ndl','qr1hi-j7d0g-a45rn6qhjszct1d','qr1hi-j7d0g-7o66z9uq8mkgqun','qr1hi-j7d0g-iodpr5gc65cp4t0','qr1hi-j7d0g-550ma2g4nlx5ri6','qr1hi-j7d0g-gsw7n4d2g3mx1dj','qr1hi-j7d0g-fpyx8sz1lkdvcaq','qr1hi-j7d0g-l1emsbyyx6wyjdh','qr1hi-j7d0g-45zjb0b4n6cpzxa','qr1hi-j7d0g-anonymouspublic') OR pipeline_instances.uuid IN (SELECT head_uuid FROM links WHERE link_class='permission' AND tail_uuid IN ('qr1hi-tpzed-w68kvgin92qp9gs', 'qr1hi-tpzed-anonymouspublic', 'qr1hi-j7d0g-xcq63k14iwywimi', 'qr1hi-j7d0g-fffffffffffffff', 'qr1hi-j7d0g-it30l961gq3t0oi', 'qr1hi-j7d0g-rluyd6zowuj1zre', 'qr1hi-j7d0g-anonymouspublic', 'qr1hi-j7d0g-662ij1pcw6bj8uj', 'qr1hi-j7d0g-ls7mn9ilxiwvep6', 'qr1hi-j7d0g-key0mqeqlvhz7v7', 'qr1hi-j7d0g-2hth2gzle63muo6', 'qr1hi-j7d0g-gytictj8fzr9jfh', 'qr1hi-j7d0g-25wprjygblp9z2f', 'qr1hi-j7d0g-ziejtm5kaik7ndl', 'qr1hi-j7d0g-a45rn6qhjszct1d', 'qr1hi-j7d0g-7o66z9uq8mkgqun', 'qr1hi-j7d0g-iodpr5gc65cp4t0', 'qr1hi-j7d0g-550ma2g4nlx5ri6', 'qr1hi-j7d0g-gsw7n4d2g3mx1dj', 'qr1hi-j7d0g-fpyx8sz1lkdvcaq', 'qr1hi-j7d0g-l1emsbyyx6wyjdh', 'qr1hi-j7d0g-45zjb0b4n6cpzxa', 'qr1hi-j7d0g-834hs5rnunpn6y6', 'qr1hi-j7d0g-up6qgpqz5ie2vfq', 'qr1hi-j7d0g-u7zg1qdaowykd8d', 'qr1hi-j7d0g-mm1t3d3mmkh7n2u', 'qr1hi-j7d0g-k40t93v1njk9gcz', 'qr1hi-j7d0g-anonymouspublic', 'qr1hi-j7d0g-2ak9yjmy5u0hw6z', 'qr1hi-j7d0g-jrzr18w1nqr5326', 'qr1hi-j7d0g-anonymouspublic', 'qr1hi-j7d0g-662ij1pcw6bj8uj', 'qr1hi-j7d0g-ls7mn9ilxiwvep6', 'qr1hi-j7d0g-key0mqeqlvhz7v7', 'qr1hi-j7d0g-2hth2gzle63muo6', 'qr1hi-j7d0g-gytictj8fzr9jfh', 'qr1hi-j7d0g-25wprjygblp9z2f', 'qr1hi-j7d0g-ziejtm5kaik7ndl', 'qr1hi-j7d0g-a45rn6qhjszct1d', 'qr1hi-j7d0g-7o66z9uq8mkgqun', 'qr1hi-j7d0g-iodpr5gc65cp4t0', 'qr1hi-j7d0g-550ma2g4nlx5ri6', 'qr1hi-j7d0g-gsw7n4d2g3mx1dj', 'qr1hi-j7d0g-fpyx8sz1lkdvcaq', 'qr1hi-j7d0g-l1emsbyyx6wyjdh', 'qr1hi-j7d0g-45zjb0b4n6cpzxa', 'qr1hi-j7d0g-anonymouspublic'))) AND ((to_tsvector('english', coalesce(uuid,'') || ' ' || coalesce(owner_uuid,'') || ' ' || coalesce(modified_by_client_uuid,'') || ' ' || coalesce(modified_by_user_uuid,'') || ' ' || coalesce(pipeline_template_uuid,'') || ' ' || coalesce(name,'') || ' ' || coalesce(components,'') || ' ' || coalesce(properties,'') || ' ' || coalesce(state,'') || ' ' || coalesce(components_summary,'') || ' ' || coalesce(description,'')) @@ to_tsquery('hash:*')));

Cold, that takes about 38 seconds; hot, 23 seconds:

 Aggregate  (cost=3274.90..3274.91 rows=1 width=4) (actual time=22667.027..22667.028 rows=1 loops=1)
   ->  Seq Scan on pipeline_instances  (cost=1186.46..3263.78 rows=4447 width=4) (actual time=40.949..22664.783 rows=1411 loops=1)
         Filter: ((to_tsvector('english'::regconfig, (((((((((((((((((((((COALESCE(uuid, ''::character varying))::text || ' '::text) || (COALESCE(owner_uuid, ''::character varying))::text) || ' '::text) || (COALESCE(modified_by_client_uuid, ''::character varying))::text) || ' '::text) || (COALESCE(modified_by_user_uuid, ''::character varying))::text) || ' '::text) || (COALESCE(pipeline_template_uuid, ''::character varying))::text) || ' '::text) || (COALESCE(name, ''::character varying))::text) || ' '::text) || COALESCE(components, ''::text)) || ' '::text) || COALESCE(properties, ''::text)) || ' '::text) || (COALESCE(state, ''::character varying))::text) || ' '::text) || COALESCE(components_summary, ''::text)) || ' '::text) || (COALESCE(description, ''::character varying))::text)) @@ to_tsquery('hash:*'::text)) AND (((uuid)::text = ANY ('{qr1hi-tpzed-w68kvgin92qp9gs,qr1hi-tpzed-anonymouspublic}'::text[])) OR ((owner_uuid)::text = ANY ('{qr1hi-tpzed-w68kvgin92qp9gs,qr1hi-tpzed-anonymouspublic,qr1hi-j7d0g-xcq63k14iwywimi,qr1hi-j7d0g-fffffffffffffff,qr1hi-j7d0g-it30l961gq3t0oi,qr1hi-j7d0g-rluyd6zowuj1zre,qr1hi-j7d0g-anonymouspublic,qr1hi-j7d0g-662ij1pcw6bj8uj,qr1hi-j7d0g-ls7mn9ilxiwvep6,qr1hi-j7d0g-key0mqeqlvhz7v7,qr1hi-j7d0g-2hth2gzle63muo6,qr1hi-j7d0g-gytictj8fzr9jfh,qr1hi-j7d0g-25wprjygblp9z2f,qr1hi-j7d0g-ziejtm5kaik7ndl,qr1hi-j7d0g-a45rn6qhjszct1d,qr1hi-j7d0g-7o66z9uq8mkgqun,qr1hi-j7d0g-iodpr5gc65cp4t0,qr1hi-j7d0g-550ma2g4nlx5ri6,qr1hi-j7d0g-gsw7n4d2g3mx1dj,qr1hi-j7d0g-fpyx8sz1lkdvcaq,qr1hi-j7d0g-l1emsbyyx6wyjdh,qr1hi-j7d0g-45zjb0b4n6cpzxa,qr1hi-j7d0g-834hs5rnunpn6y6,qr1hi-j7d0g-up6qgpqz5ie2vfq,qr1hi-j7d0g-u7zg1qdaowykd8d,qr1hi-j7d0g-mm1t3d3mmkh7n2u,qr1hi-j7d0g-k40t93v1njk9gcz,qr1hi-j7d0g-anonymouspublic,qr1hi-j7d0g-2ak9yjmy5u0hw6z,qr1hi-j7d0g-jrzr18w1nqr5326,qr1hi-j7d0g-anonymouspublic,qr1hi-j7d0g-662ij1pcw6bj8uj,qr1hi-j7d0g-ls7mn9ilxiwvep6,qr1hi-j7d0g-key0mqeqlvhz7v7,qr1hi-j7d0g-2hth2gzle63muo6,qr1hi-j7d0g-gytictj8fzr9jfh,qr1hi-j7d0g-25wprjygblp9z2f,qr1hi-j7d0g-ziejtm5kaik7ndl,qr1hi-j7d0g-a45rn6qhjszct1d,qr1hi-j7d0g-7o66z9uq8mkgqun,qr1hi-j7d0g-iodpr5gc65cp4t0,qr1hi-j7d0g-550ma2g4nlx5ri6,qr1hi-j7d0g-gsw7n4d2g3mx1dj,qr1hi-j7d0g-fpyx8sz1lkdvcaq,qr1hi-j7d0g-l1emsbyyx6wyjdh,qr1hi-j7d0g-45zjb0b4n6cpzxa,qr1hi-j7d0g-anonymouspublic}'::text[])) OR (hashed SubPlan 1)))
         SubPlan 1
           ->  Bitmap Heap Scan on links  (cost=191.35..1186.37 rows=34 width=28) (actual time=0.568..1.111 rows=57 loops=1)
                 Recheck Cond: ((tail_uuid)::text = ANY ('{qr1hi-tpzed-w68kvgin92qp9gs,qr1hi-tpzed-anonymouspublic,qr1hi-j7d0g-xcq63k14iwywimi,qr1hi-j7d0g-fffffffffffffff,qr1hi-j7d0g-it30l961gq3t0oi,qr1hi-j7d0g-rluyd6zowuj1zre,qr1hi-j7d0g-anonymouspublic,qr1hi-j7d0g-662ij1pcw6bj8uj,qr1hi-j7d0g-ls7mn9ilxiwvep6,qr1hi-j7d0g-key0mqeqlvhz7v7,qr1hi-j7d0g-2hth2gzle63muo6,qr1hi-j7d0g-gytictj8fzr9jfh,qr1hi-j7d0g-25wprjygblp9z2f,qr1hi-j7d0g-ziejtm5kaik7ndl,qr1hi-j7d0g-a45rn6qhjszct1d,qr1hi-j7d0g-7o66z9uq8mkgqun,qr1hi-j7d0g-iodpr5gc65cp4t0,qr1hi-j7d0g-550ma2g4nlx5ri6,qr1hi-j7d0g-gsw7n4d2g3mx1dj,qr1hi-j7d0g-fpyx8sz1lkdvcaq,qr1hi-j7d0g-l1emsbyyx6wyjdh,qr1hi-j7d0g-45zjb0b4n6cpzxa,qr1hi-j7d0g-834hs5rnunpn6y6,qr1hi-j7d0g-up6qgpqz5ie2vfq,qr1hi-j7d0g-u7zg1qdaowykd8d,qr1hi-j7d0g-mm1t3d3mmkh7n2u,qr1hi-j7d0g-k40t93v1njk9gcz,qr1hi-j7d0g-anonymouspublic,qr1hi-j7d0g-2ak9yjmy5u0hw6z,qr1hi-j7d0g-jrzr18w1nqr5326,qr1hi-j7d0g-anonymouspublic,qr1hi-j7d0g-662ij1pcw6bj8uj,qr1hi-j7d0g-ls7mn9ilxiwvep6,qr1hi-j7d0g-key0mqeqlvhz7v7,qr1hi-j7d0g-2hth2gzle63muo6,qr1hi-j7d0g-gytictj8fzr9jfh,qr1hi-j7d0g-25wprjygblp9z2f,qr1hi-j7d0g-ziejtm5kaik7ndl,qr1hi-j7d0g-a45rn6qhjszct1d,qr1hi-j7d0g-7o66z9uq8mkgqun,qr1hi-j7d0g-iodpr5gc65cp4t0,qr1hi-j7d0g-550ma2g4nlx5ri6,qr1hi-j7d0g-gsw7n4d2g3mx1dj,qr1hi-j7d0g-fpyx8sz1lkdvcaq,qr1hi-j7d0g-l1emsbyyx6wyjdh,qr1hi-j7d0g-45zjb0b4n6cpzxa,qr1hi-j7d0g-anonymouspublic}'::text[]))
                 Filter: ((link_class)::text = 'permission'::text)
                 ->  Bitmap Index Scan on index_links_on_tail_uuid  (cost=0.00..191.34 rows=455 width=0) (actual time=0.551..0.551 rows=418 loops=1)
                       Index Cond: ((tail_uuid)::text = ANY ('{qr1hi-tpzed-w68kvgin92qp9gs,qr1hi-tpzed-anonymouspublic,qr1hi-j7d0g-xcq63k14iwywimi,qr1hi-j7d0g-fffffffffffffff,qr1hi-j7d0g-it30l961gq3t0oi,qr1hi-j7d0g-rluyd6zowuj1zre,qr1hi-j7d0g-anonymouspublic,qr1hi-j7d0g-662ij1pcw6bj8uj,qr1hi-j7d0g-ls7mn9ilxiwvep6,qr1hi-j7d0g-key0mqeqlvhz7v7,qr1hi-j7d0g-2hth2gzle63muo6,qr1hi-j7d0g-gytictj8fzr9jfh,qr1hi-j7d0g-25wprjygblp9z2f,qr1hi-j7d0g-ziejtm5kaik7ndl,qr1hi-j7d0g-a45rn6qhjszct1d,qr1hi-j7d0g-7o66z9uq8mkgqun,qr1hi-j7d0g-iodpr5gc65cp4t0,qr1hi-j7d0g-550ma2g4nlx5ri6,qr1hi-j7d0g-gsw7n4d2g3mx1dj,qr1hi-j7d0g-fpyx8sz1lkdvcaq,qr1hi-j7d0g-l1emsbyyx6wyjdh,qr1hi-j7d0g-45zjb0b4n6cpzxa,qr1hi-j7d0g-834hs5rnunpn6y6,qr1hi-j7d0g-up6qgpqz5ie2vfq,qr1hi-j7d0g-u7zg1qdaowykd8d,qr1hi-j7d0g-mm1t3d3mmkh7n2u,qr1hi-j7d0g-k40t93v1njk9gcz,qr1hi-j7d0g-anonymouspublic,qr1hi-j7d0g-2ak9yjmy5u0hw6z,qr1hi-j7d0g-jrzr18w1nqr5326,qr1hi-j7d0g-anonymouspublic,qr1hi-j7d0g-662ij1pcw6bj8uj,qr1hi-j7d0g-ls7mn9ilxiwvep6,qr1hi-j7d0g-key0mqeqlvhz7v7,qr1hi-j7d0g-2hth2gzle63muo6,qr1hi-j7d0g-gytictj8fzr9jfh,qr1hi-j7d0g-25wprjygblp9z2f,qr1hi-j7d0g-ziejtm5kaik7ndl,qr1hi-j7d0g-a45rn6qhjszct1d,qr1hi-j7d0g-7o66z9uq8mkgqun,qr1hi-j7d0g-iodpr5gc65cp4t0,qr1hi-j7d0g-550ma2g4nlx5ri6,qr1hi-j7d0g-gsw7n4d2g3mx1dj,qr1hi-j7d0g-fpyx8sz1lkdvcaq,qr1hi-j7d0g-l1emsbyyx6wyjdh,qr1hi-j7d0g-45zjb0b4n6cpzxa,qr1hi-j7d0g-anonymouspublic}'::text[]))
 Total runtime: 22667.129 ms
(10 rows)

Subtasks

Task #6106: Add a performance test case that exposes the slow queryClosedTom Clegg

Task #6112: Review 6098-full-text-index 64cfaedResolvedTom Clegg

Task #6122: Improve query performance (or prevent clients from doing it?)ResolvedTom Clegg

Task #6150: Test correct index usage with "explain analyze"ClosedTom Clegg

Associated revisions

Revision 59d68bda
Added by Tom Clegg over 4 years ago

Merge branch '6098-full-text-index' refs #6098

History

#1 Updated by Ward Vandewege over 4 years ago

  • Story points set to 0.5

#2 Updated by Tom Clegg over 4 years ago

  • Category set to API
  • Assigned To set to Tom Clegg

#3 Updated by Ward Vandewege over 4 years ago

  • Description updated (diff)

#4 Updated by Ward Vandewege over 4 years ago

  • Description updated (diff)

#5 Updated by Tom Clegg over 4 years ago

  • Story points changed from 0.5 to 1.0

#6 Updated by Tom Clegg over 4 years ago

Definitely a full-text search problem ("explain" on the query minus the "@@" condition says 73ms). Presumably the index isn't doing its job.

#7 Updated by Tom Clegg over 4 years ago

Removing the "uuid" field from the full text index (and query) moves my test query time from 1075ms to 4ms.

#8 Updated by Tom Clegg over 4 years ago

This query takes 1075ms.

arvados_production=> CREATE INDEX tmp_idx ON pipeline_instances USING gin (to_tsvector('english'::regconfig, COALESCE(uuid, ''::character varying)::text || ' '::text || COALESCE(owner_uuid, ''::character varying)::text || ' '::text || COALESCE(modified_by_client_uuid, ''::character varying)::text || ' '::text || COALESCE(modified_by_user_uuid, ''::character varying)::text || ' '::text || COALESCE(pipeline_template_uuid, ''::character varying)::text || ' '::text || COALESCE(name, ''::character varying)::text || ' '::text || COALESCE(components, ''::text) || ' '::text || COALESCE(properties, ''::text) || ' '::text || COALESCE(state, ''::character varying)::text || ' '::text || COALESCE(components_summary, ''::text) || ' '::text || COALESCE(description, ''::character varying)::text));CREATE INDEX
arvados_production=> explain analyze SELECT COUNT(DISTINCT "pipeline_instances"."id") FROM "pipeline_instances"  WHERE to_tsvector('english'::regconfig, COALESCE(uuid, ''::character varying)::text || ' '::text || COALESCE(owner_uuid, ''::character varying)::text || ' '::text || COALESCE(modified_by_client_uuid, ''::character varying)::text || ' '::text || COALESCE(modified_by_user_uuid, ''::character varying)::text || ' '::text || COALESCE(pipeline_template_uuid, ''::character varying)::text || ' '::text || COALESCE(name, ''::character varying)::text || ' '::text || COALESCE(components, ''::text) || ' '::text || COALESCE(properties, ''::text) || ' '::text || COALESCE(state, ''::character varying)::text || ' '::text || COALESCE(components_summary, ''::text) || ' '::text || COALESCE(description, ''::character varying)::text) @@ to_tsquery('hash:*');
arvados_production=> drop index tmp_idx;
DROP INDEX

With the same data, but adding "' '::text || " to the front of the to_tsvector() argument in the index and the query, the query takes 4ms.

arvados_production=> CREATE INDEX tmp_idx ON pipeline_instances USING gin (to_tsvector('english'::regconfig, ' '::text || COALESCE(uuid, ''::character varying)::text || ' '::text || COALESCE(owner_uuid, ''::character varying)::text || ' '::text || COALESCE(modified_by_client_uuid, ''::character varying)::text || ' '::text || COALESCE(modified_by_user_uuid, ''::character varying)::text || ' '::text || COALESCE(pipeline_template_uuid, ''::character varying)::text || ' '::text || COALESCE(name, ''::character varying)::text || ' '::text || COALESCE(components, ''::text) || ' '::text || COALESCE(properties, ''::text) || ' '::text || COALESCE(state, ''::character varying)::text || ' '::text || COALESCE(components_summary, ''::text) || ' '::text || COALESCE(description, ''::character varying)::text));CREATE INDEX
arvados_production=> explain analyze SELECT COUNT(DISTINCT "pipeline_instances"."id") FROM "pipeline_instances"  WHERE to_tsvector('english'::regconfig, ' '::text || COALESCE(uuid, ''::character varying)::text || ' '::text || COALESCE(owner_uuid, ''::character varying)::text || ' '::text || COALESCE(modified_by_client_uuid, ''::character varying)::text || ' '::text || COALESCE(modified_by_user_uuid, ''::character varying)::text || ' '::text || COALESCE(pipeline_template_uuid, ''::character varying)::text || ' '::text || COALESCE(name, ''::character varying)::text || ' '::text || COALESCE(components, ''::text) || ' '::text || COALESCE(properties, ''::text) || ' '::text || COALESCE(state, ''::character varying)::text || ' '::text || COALESCE(components_summary, ''::text) || ' '::text || COALESCE(description, ''::character varying)::text) @@ to_tsquery('hash:*');
arvados_production=> drop index tmp_idx;
DROP INDEX

Apparently, if the first thing listed in the long string-concatenation expression in the query happens to be a column with its own index (e.g., uuid) Postgres uses that column index, even though it's obvious (to us) that the full text index is a better choice. The index performs fine if the first columns is owner_uuid that doesn't have its own index, which is why our full text search has been working well for collections.

We can work around this by starting off the expression with a space.

#9 Updated by Radhika Chippada over 4 years ago

  • Status changed from New to In Progress

#10 Updated by Radhika Chippada over 4 years ago

LGTM

Just one additional comment request: can you please add a comment to the effect "check if search indexes are already correct by looking at one of them" before line #5?

Also, did your exploration into this fix lead to any interesting urls? If so, please add them to the ticket. Thanks.

#11 Updated by Ward Vandewege over 4 years ago

After deploying this evening, still slow (though the api server was under very heavy load at the time):

                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                     QUERY PLAN                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                          
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Aggregate  (cost=3286.50..3286.51 rows=1 width=4) (actual time=28263.018..28263.019 rows=1 loops=1)
   ->  Seq Scan on pipeline_instances  (cost=1186.46..3286.27 rows=91 width=4) (actual time=1.328..28259.854 rows=1454 loops=1)
         Filter: ((to_tsvector('english'::regconfig, (((((((((((((((((((((COALESCE(uuid, ''::character varying))::text || ' '::text) || (COALESCE(owner_uuid, ''::character varying))::text) || ' '::text) || (COALESCE(modified_by_client_uuid, ''::character varying))::text) || ' '::text) || (COALESCE(modified_by_user_uuid, ''::character varying))::text) || ' '::text) || (COALESCE(pipeline_template_uuid, ''::character varying))::text) || ' '::text) || (COALESCE(name, ''::character varying))::text) || ' '::text) || COALESCE(components, ''::text)) || ' '::text) || COALESCE(properties, ''::text)) || ' '::text) || (COALESCE(state, ''::character varying))::text) || ' '::text) || COALESCE(components_summary, ''::text)) || ' '::text) || (COALESCE(description, ''::character varying))::text)) @@ to_tsquery('hash:*'::text)) AND (((uuid)::text = ANY ('{qr1hi-tpzed-w68kvgin92qp9gs,qr1hi-tpzed-anonymouspublic}'::text[])) OR ((owner_uuid)::text = ANY ('{qr1hi-tpzed-w68kvgin92qp9gs,qr1hi-tpzed-anonymouspublic,qr1hi-j7d0g-xcq63k14iwywimi,qr1hi-j7d0g-fffffffffffffff,qr1hi-j7d0g-it30l961gq3t0oi,qr1hi-j7d0g-rluyd6zowuj1zre,qr1hi-j7d0g-anonymouspublic,qr1hi-j7d0g-662ij1pcw6bj8uj,qr1hi-j7d0g-ls7mn9ilxiwvep6,qr1hi-j7d0g-key0mqeqlvhz7v7,qr1hi-j7d0g-2hth2gzle63muo6,qr1hi-j7d0g-gytictj8fzr9jfh,qr1hi-j7d0g-25wprjygblp9z2f,qr1hi-j7d0g-ziejtm5kaik7ndl,qr1hi-j7d0g-a45rn6qhjszct1d,qr1hi-j7d0g-7o66z9uq8mkgqun,qr1hi-j7d0g-iodpr5gc65cp4t0,qr1hi-j7d0g-550ma2g4nlx5ri6,qr1hi-j7d0g-gsw7n4d2g3mx1dj,qr1hi-j7d0g-fpyx8sz1lkdvcaq,qr1hi-j7d0g-l1emsbyyx6wyjdh,qr1hi-j7d0g-45zjb0b4n6cpzxa,qr1hi-j7d0g-834hs5rnunpn6y6,qr1hi-j7d0g-up6qgpqz5ie2vfq,qr1hi-j7d0g-u7zg1qdaowykd8d,qr1hi-j7d0g-mm1t3d3mmkh7n2u,qr1hi-j7d0g-k40t93v1njk9gcz,qr1hi-j7d0g-anonymouspublic,qr1hi-j7d0g-2ak9yjmy5u0hw6z,qr1hi-j7d0g-jrzr18w1nqr5326,qr1hi-j7d0g-anonymouspublic,qr1hi-j7d0g-662ij1pcw6bj8uj,qr1hi-j7d0g-ls7mn9ilxiwvep6,qr1hi-j7d0g-key0mqeqlvhz7v7,qr1hi-j7d0g-2hth2gzle63muo6,qr1hi-j7d0g-gytictj8fzr9jfh,qr1hi-j7d0g-25wprjygblp9z2f,qr1hi-j7d0g-ziejtm5kaik7ndl,qr1hi-j7d0g-a45rn6qhjszct1d,qr1hi-j7d0g-7o66z9uq8mkgqun,qr1hi-j7d0g-iodpr5gc65cp4t0,qr1hi-j7d0g-550ma2g4nlx5ri6,qr1hi-j7d0g-gsw7n4d2g3mx1dj,qr1hi-j7d0g-fpyx8sz1lkdvcaq,qr1hi-j7d0g-l1emsbyyx6wyjdh,qr1hi-j7d0g-45zjb0b4n6cpzxa,qr1hi-j7d0g-anonymouspublic}'::text[])) OR (hashed SubPlan 1)))
         SubPlan 1
           ->  Bitmap Heap Scan on links  (cost=191.35..1186.37 rows=34 width=28) (actual time=0.846..1.799 rows=57 loops=1)
                 Recheck Cond: ((tail_uuid)::text = ANY ('{qr1hi-tpzed-w68kvgin92qp9gs,qr1hi-tpzed-anonymouspublic,qr1hi-j7d0g-xcq63k14iwywimi,qr1hi-j7d0g-fffffffffffffff,qr1hi-j7d0g-it30l961gq3t0oi,qr1hi-j7d0g-rluyd6zowuj1zre,qr1hi-j7d0g-anonymouspublic,qr1hi-j7d0g-662ij1pcw6bj8uj,qr1hi-j7d0g-ls7mn9ilxiwvep6,qr1hi-j7d0g-key0mqeqlvhz7v7,qr1hi-j7d0g-2hth2gzle63muo6,qr1hi-j7d0g-gytictj8fzr9jfh,qr1hi-j7d0g-25wprjygblp9z2f,qr1hi-j7d0g-ziejtm5kaik7ndl,qr1hi-j7d0g-a45rn6qhjszct1d,qr1hi-j7d0g-7o66z9uq8mkgqun,qr1hi-j7d0g-iodpr5gc65cp4t0,qr1hi-j7d0g-550ma2g4nlx5ri6,qr1hi-j7d0g-gsw7n4d2g3mx1dj,qr1hi-j7d0g-fpyx8sz1lkdvcaq,qr1hi-j7d0g-l1emsbyyx6wyjdh,qr1hi-j7d0g-45zjb0b4n6cpzxa,qr1hi-j7d0g-834hs5rnunpn6y6,qr1hi-j7d0g-up6qgpqz5ie2vfq,qr1hi-j7d0g-u7zg1qdaowykd8d,qr1hi-j7d0g-mm1t3d3mmkh7n2u,qr1hi-j7d0g-k40t93v1njk9gcz,qr1hi-j7d0g-anonymouspublic,qr1hi-j7d0g-2ak9yjmy5u0hw6z,qr1hi-j7d0g-jrzr18w1nqr5326,qr1hi-j7d0g-anonymouspublic,qr1hi-j7d0g-662ij1pcw6bj8uj,qr1hi-j7d0g-ls7mn9ilxiwvep6,qr1hi-j7d0g-key0mqeqlvhz7v7,qr1hi-j7d0g-2hth2gzle63muo6,qr1hi-j7d0g-gytictj8fzr9jfh,qr1hi-j7d0g-25wprjygblp9z2f,qr1hi-j7d0g-ziejtm5kaik7ndl,qr1hi-j7d0g-a45rn6qhjszct1d,qr1hi-j7d0g-7o66z9uq8mkgqun,qr1hi-j7d0g-iodpr5gc65cp4t0,qr1hi-j7d0g-550ma2g4nlx5ri6,qr1hi-j7d0g-gsw7n4d2g3mx1dj,qr1hi-j7d0g-fpyx8sz1lkdvcaq,qr1hi-j7d0g-l1emsbyyx6wyjdh,qr1hi-j7d0g-45zjb0b4n6cpzxa,qr1hi-j7d0g-anonymouspublic}'::text[]))
                 Filter: ((link_class)::text = 'permission'::text)
                 ->  Bitmap Index Scan on index_links_on_tail_uuid  (cost=0.00..191.34 rows=455 width=0) (actual time=0.815..0.815 rows=418 loops=1)
                       Index Cond: ((tail_uuid)::text = ANY ('{qr1hi-tpzed-w68kvgin92qp9gs,qr1hi-tpzed-anonymouspublic,qr1hi-j7d0g-xcq63k14iwywimi,qr1hi-j7d0g-fffffffffffffff,qr1hi-j7d0g-it30l961gq3t0oi,qr1hi-j7d0g-rluyd6zowuj1zre,qr1hi-j7d0g-anonymouspublic,qr1hi-j7d0g-662ij1pcw6bj8uj,qr1hi-j7d0g-ls7mn9ilxiwvep6,qr1hi-j7d0g-key0mqeqlvhz7v7,qr1hi-j7d0g-2hth2gzle63muo6,qr1hi-j7d0g-gytictj8fzr9jfh,qr1hi-j7d0g-25wprjygblp9z2f,qr1hi-j7d0g-ziejtm5kaik7ndl,qr1hi-j7d0g-a45rn6qhjszct1d,qr1hi-j7d0g-7o66z9uq8mkgqun,qr1hi-j7d0g-iodpr5gc65cp4t0,qr1hi-j7d0g-550ma2g4nlx5ri6,qr1hi-j7d0g-gsw7n4d2g3mx1dj,qr1hi-j7d0g-fpyx8sz1lkdvcaq,qr1hi-j7d0g-l1emsbyyx6wyjdh,qr1hi-j7d0g-45zjb0b4n6cpzxa,qr1hi-j7d0g-834hs5rnunpn6y6,qr1hi-j7d0g-up6qgpqz5ie2vfq,qr1hi-j7d0g-u7zg1qdaowykd8d,qr1hi-j7d0g-mm1t3d3mmkh7n2u,qr1hi-j7d0g-k40t93v1njk9gcz,qr1hi-j7d0g-anonymouspublic,qr1hi-j7d0g-2ak9yjmy5u0hw6z,qr1hi-j7d0g-jrzr18w1nqr5326,qr1hi-j7d0g-anonymouspublic,qr1hi-j7d0g-662ij1pcw6bj8uj,qr1hi-j7d0g-ls7mn9ilxiwvep6,qr1hi-j7d0g-key0mqeqlvhz7v7,qr1hi-j7d0g-2hth2gzle63muo6,qr1hi-j7d0g-gytictj8fzr9jfh,qr1hi-j7d0g-25wprjygblp9z2f,qr1hi-j7d0g-ziejtm5kaik7ndl,qr1hi-j7d0g-a45rn6qhjszct1d,qr1hi-j7d0g-7o66z9uq8mkgqun,qr1hi-j7d0g-iodpr5gc65cp4t0,qr1hi-j7d0g-550ma2g4nlx5ri6,qr1hi-j7d0g-gsw7n4d2g3mx1dj,qr1hi-j7d0g-fpyx8sz1lkdvcaq,qr1hi-j7d0g-l1emsbyyx6wyjdh,qr1hi-j7d0g-45zjb0b4n6cpzxa,qr1hi-j7d0g-anonymouspublic}'::text[]))
 Total runtime: 28263.235 ms
(10 rows)

#12 Updated by Radhika Chippada over 4 years ago

  • Status changed from In Progress to Resolved

Ward later confirmed that the note #11 is quoting an incorrect (old) log snippet and search is working much faster now.

Also available in: Atom PDF