Arvados

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

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

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.

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.

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)