Bug #14576
Updated by Ward Vandewege over 5 years ago
Now that qr1hi is on the latest rc for 1.3.0, we're seeing a lot of slow postgres queries like this one:
<pre>
arvados_production=# explain analyze SELECT collections."uuid", collections."owner_uuid", collections."created_at", collections."modified_by_client_uuid", collections."modified_by_user_uuid", collections."modified_at", collections."name", collections."description", collections."properties", collections."portable_data_hash", collections."replication_desired", collections."replication_confirmed", collections."replication_confirmed_at", collections."storage_classes_desired", collections."storage_classes_confirmed", collections."storage_classes_confirmed_at", collections."delete_at", collections."trash_at", collections."is_trashed", collections."version", collections."current_version_uuid", collections."preserve_version" FROM "collections" WHERE (NOT EXISTS(SELECT 1 FROM materialized_permission_view WHERE trashed = 1 AND (collections.owner_uuid = target_uuid)) AND collections.is_trashed = false AND collections.uuid = collections.current_version_uuid) ORDER BY collections.modified_at desc, collections.uuid LIMIT 8 OFFSET 0;
QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Limit (cost=5470.02..5470.02 rows=1 width=365) (actual time=2533.780..2533.784 rows=8 loops=1)
-> Sort (cost=5470.02..5470.02 rows=1 width=365) (actual time=2533.778..2533.779 rows=8 loops=1)
Sort Key: collections.modified_at DESC, collections.uuid
Sort Method: top-N heapsort Memory: 29kB
-> Merge Anti Join (cost=5450.80..5470.01 rows=1 width=365) (actual time=1878.913..2399.362 rows=205414 loops=1)
Merge Cond: ((collections.owner_uuid)::text = (materialized_permission_view.target_uuid)::text)
-> Sort (cost=3323.06..3325.62 rows=1027 width=365) (actual time=1878.715..2227.890 rows=205414 loops=1)
Sort Key: collections.owner_uuid
Sort Method: external merge Disk: 53680kB
-> Bitmap Heap Scan on collections (cost=53.81..3271.69 rows=1027 width=365) (actual time=53.099..341.265 rows=205414 loops=1)
Recheck Cond: ((NOT is_trashed) AND ((current_version_uuid)::text = (uuid)::text))
Heap Blocks: exact=14972
-> Bitmap Index Scan on index_collections_on_owner_uuid_and_name (cost=0.00..53.55 rows=1027 width=0) (actual time=48.443..48.443 rows=205415 loops=1)
-> Sort (cost=2127.72..2131.33 rows=1447 width=28) (actual time=0.191..0.192 rows=12 loops=1)
Sort Key: materialized_permission_view.target_uuid
Sort Method: quicksort Memory: 25kB
-> Index Only Scan using permission_target_trashed on materialized_permission_view (cost=0.42..2051.76 rows=1447 width=28) (actual time=0.139..0.156 rows=12 loops=1)
Index Cond: (trashed = 1)
Heap Fetches: 12
Planning time: 3.400 ms
Execution time: 2547.024 ms
(21 rows)
</pre>