0

I have this query which has suddenly turned really really slow

select * 
from satelliteproduct 
where supplier_id = 226 
and supplierproduct_id IN ('123', '234');

If I query an explain analyze I can see that it is actually doing a seq scan instead of using the indexes.

Index Scan using unq_satelliteproduct_0 on satelliteproduct (cost=0.69..2.71 rows=1 width=2593)    
  Index Cond: (supplier_id = 226)
  Filter: ((supplierproduct_id)::text = ANY ('{123,234}'::text[]))

The weird thing though is if change the value of supplier_id and it suddenly becomes really fast and I can see that it does use the indexes properly, ie

Index Scan using unq_satelliteproduct_0 on satelliteproduct (cost=0.69..4.41 rows=1 width=2593) (actual time=0.088..0.089 rows=0 loops=1)    
  Index Cond: ((supplier_id = 4207) AND ((supplierproduct_id)::text = ANY ('{123,234}'::text[])))

Any idea? It started happening after an "abrupt" shutdown when data was being inserted. The db recovered well and I performed a vacuum analyze.

EDIT

Information on the indexes, from \d+ satelliteproduct

                                          Table 

"public.satelliteproduct"
       Column       |            Type             | Collation | Nullable | Default | Storage  | Stats target | Description
--------------------+-----------------------------+-----------+----------+---------+----------+--------------+-------------
 productid          | character varying(100)      |           | not null |         | extended |              |
 center             | geometry                    |           |          |         | main     |              |
 cloud              | double precision            |           |          |         | plain    |              |
 gsd                | double precision            |           |          |         | plain    |              |
 hashvalue          | character varying(100)      |           |          |         | extended |              |
 ona                | double precision            |           |          |         | plain    |              |
 orbit              | integer                     |           |          |         | plain    |              |
 orbitdirection     | character varying(255)      |           |          |         | extended |              |
 originalql         | character varying(1000)     |           |          |         | extended |              |
 oza                | double precision            |           |          |         | plain    |              |
 polarisation       | character varying(255)      |           |          |         | extended |              |
 quicklookurl       | character varying(1000)     |           |          |         | extended |              |
 sensormode_id      | bigint                      |           |          |         | plain    |              |
 startacq           | timestamp without time zone |           |          |         | plain    |              |
 stopacq            | timestamp without time zone |           |          |         | plain    |              |
 stripid            | character varying(100)      |           |          |         | extended |              |
 supplierproduct_id | character varying(100)      |           |          |         | extended |              |
 sza                | double precision            |           |          |         | plain    |              |
 thumbnailurl       | character varying(1000)     |           |          |         | extended |              |
 sensorbeam_id      | bigint                      |           |          |         | plain    |              |
 supplier_id        | bigint                      |           |          |         | plain    |              |
 footgeom           | geometry                    |           |          |         | main     |              |
 footgeog           | geography                   |           |          |         | main     |              |
 vendorparameters   | json                        |           |          |         | extended |              |
 stereo             | character varying(1000)     |           |          |         | extended |              |
Indexes:
    "satelliteproduct_pkey" PRIMARY KEY, btree (productid)
    "unq_satelliteproduct_0" UNIQUE CONSTRAINT, btree (supplier_id, supplierproduct_id)
    "footgeogidx" gist (footgeog)
    "sensormodeidx" btree (sensormode_id)
    "starttimeidx" btree (startacq)
    "supplierproductidx" btree (supplierproduct_id)
    "timerangeidx" btree (startacq, stopacq)
Foreign-key constraints:
    "fk_satelliteproduct_sensorbeam_id" FOREIGN KEY (sensorbeam_id) REFERENCES sensorbeam(id)
    "fk_satelliteproduct_supplier_id" FOREIGN KEY (supplier_id) REFERENCES supplier(id)

Postgres version from select version();

PostgreSQL 11.10 on x86_64-pc-linux-gnu, compiled by gcc (Debian 8.3.0-6) 8.3.0, 64-bit

Regarding cardinality, there are around 40M+ rows.

The database runs on a k8s pod, with 8GB RAM, in a primary / read configuration. This is the primary db and is only used for building the database content.

I can also add that if I run the following query

select * 
from satelliteproduct 
where supplier_id = 226 
and supplierproduct_id '123';

Then the result is immediate. BUT if I run

select * 
from satelliteproduct 
where supplier_id = 226 
and supplierproduct_id IN ('123', '234');

(notice the difference is with the IN) then it takes 10mns!

I haven't yet dropped and rebuilt all indexes, just a vacuum analyze. I will do if you think it's worth it given the new information I provided.

Edit 2

I did some more tests.

Dead tuples

 schemaname |      relname      | n_live_tup | n_dead_tup | last_autovacuum
------------+-------------------+------------+------------+-----------------
 public     | satelliteproduct  |     376841 |     665594 |
 pg_catalog | pg_depend         |          0 |         77 |
 pg_toast   | pg_toast_18014    |         18 |         30 |
 public     | importtask        |       2383 |        242 |
 pg_toast   | pg_toast_17987    |       3839 |        313 |
 public     | importplannedtask |          4 |         17 |
 pg_catalog | pg_statistic      |          0 |         16 |
 pg_toast   | pg_toast_2619     |          1 |         13 |
 public     | ingestor          |          0 |         12 |
 pg_catalog | pg_class          |          0 |          5 |
(10 rows)

I retried the vacuum first, this time with Verbose, looks like the vacuum hadn't worked properly before

VACUUM (VERBOSE) satelliteproduct;
INFO:  vacuuming "public.satelliteproduct"
INFO:  scanned index "satelliteproduct_pkey" to remove 7555703 row versions
DETAIL:  CPU: user: 34.66 s, system: 0.61 s, elapsed: 90.05 s
INFO:  scanned index "supplierproductidx" to remove 7555703 row versions
DETAIL:  CPU: user: 14.25 s, system: 2.91 s, elapsed: 102.94 s
INFO:  scanned index "sensormodeidx" to remove 7555703 row versions
DETAIL:  CPU: user: 9.13 s, system: 0.99 s, elapsed: 43.63 s
INFO:  scanned index "timerangeidx" to remove 7555703 row versions
DETAIL:  CPU: user: 11.79 s, system: 1.62 s, elapsed: 60.37 s
INFO:  scanned index "unq_satelliteproduct_0" to remove 7555703 row versions
DETAIL:  CPU: user: 13.38 s, system: 3.42 s, elapsed: 106.99 s
INFO:  scanned index "footgeogidx" to remove 7555703 row versions
DETAIL:  CPU: user: 30.42 s, system: 15.87 s, elapsed: 296.25 s
INFO:  scanned index "starttimeidx" to remove 7555703 row versions
DETAIL:  CPU: user: 15.63 s, system: 1.45 s, elapsed: 37.39 s

INFO:  "satelliteproduct": removed 7555703 row versions in 2869127 pages
DETAIL:  CPU: user: 44.09 s, system: 71.27 s, elapsed: 988.56 s
INFO:  index "satelliteproduct_pkey" now contains 43594250 row versions in 455245 pages
DETAIL:  636552 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s.
INFO:  index "supplierproductidx" now contains 43594250 row versions in 666798 pages
DETAIL:  636608 index row versions were removed.
68878 index pages have been deleted, 68878 are currently reusable.
CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s.
INFO:  index "sensormodeidx" now contains 43594250 row versions in 282910 pages
DETAIL:  636608 index row versions were removed.
50164 index pages have been deleted, 49125 are currently reusable.
CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s.
INFO:  index "timerangeidx" now contains 43594250 row versions in 389866 pages
DETAIL:  636608 index row versions were removed.
49768 index pages have been deleted, 47283 are currently reusable.
CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s.
INFO:  index "unq_satelliteproduct_0" now contains 43594250 row versions in 693222 pages
DETAIL:  559271 index row versions were removed.
78266 index pages have been deleted, 78266 are currently reusable.
CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s.
INFO:  index "footgeogidx" now contains 43594250 row versions in 651770 pages
DETAIL:  6631953 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU: user: 1.83 s, system: 2.73 s, elapsed: 100.58 s.
INFO:  index "starttimeidx" now contains 43594250 row versions in 159747 pages
DETAIL:  7467607 index row versions were removed.
20350 index pages have been deleted, 3620 are currently reusable.
CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s.
INFO:  "satelliteproduct": found 363675 removable, 26890882 nonremovable row versions in 5931351 out of 9092079 pages
DETAIL:  0 dead row versions cannot be removed yet, oldest xmin: 224173
There were 7774835 unused item pointers.
Skipped 0 pages due to buffer pins, 136118 frozen pages.
0 pages are entirely empty.
CPU: user: 196.80 s, system: 134.80 s, elapsed: 2722.42 s.
INFO:  vacuuming "pg_toast.pg_toast_17987"
INFO:  scanned index "pg_toast_17987_index" to remove 455 row versions
DETAIL:  CPU: user: 0.59 s, system: 0.06 s, elapsed: 3.21 s
INFO:  "pg_toast_17987": removed 455 row versions in 131 pages
DETAIL:  CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
INFO:  index "pg_toast_17987_index" now contains 7505213 row versions in 20884 pages
DETAIL:  455 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s.
INFO:  "pg_toast_17987": found 276 removable, 61422 nonremovable row versions in 6540 out of 366398 pages
DETAIL:  0 dead row versions cannot be removed yet, oldest xmin: 224173
There were 168 unused item pointers.
Skipped 0 pages due to buffer pins, 0 frozen pages.
0 pages are entirely empty.
CPU: user: 0.65 s, system: 0.10 s, elapsed: 4.39 s.
VACUUM

I checked for anything stopping the vacuum process from working properly

No long queries, no lingering replication slots, no stale prepared statements...

 slot_name | slot_type | database | xmin
-----------+-----------+----------+------
(0 rows)

 gid | prepared | owner | database | xmin
-----+----------+-------+----------+------
(0 rows)

I rerun the vacuum verbose this time to check all was fine

VACUUM (VERBOSE) satelliteproduct;
INFO:  vacuuming "public.satelliteproduct"
INFO:  index "footgeogidx" now contains 43594250 row versions in 651770 pages
DETAIL:  0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU: user: 1.86 s, system: 2.73 s, elapsed: 99.72 s.
INFO:  "satelliteproduct": found 0 removable, 7 nonremovable row versions in 1 out of 9092079 pages
DETAIL:  0 dead row versions cannot be removed yet, oldest xmin: 224173
There were 0 unused item pointers.
Skipped 0 pages due to buffer pins, 340829 frozen pages.
0 pages are entirely empty.
CPU: user: 2.23 s, system: 2.73 s, elapsed: 100.15 s.
INFO:  vacuuming "pg_toast.pg_toast_17987"
INFO:  "pg_toast_17987": found 0 removable, 23 nonremovable row versions in 1 out of 366398 pages
DETAIL:  0 dead row versions cannot be removed yet, oldest xmin: 224173
There were 0 unused item pointers.
Skipped 0 pages due to buffer pins, 0 frozen pages.
0 pages are entirely empty.
CPU: user: 0.01 s, system: 0.00 s, elapsed: 0.01 s.
VACUUM

BUT I still get the same query times, ie < 1ms for supplierproduct_id = '123' and > 1mn for supplierproduct_id IN('123', '123')

EDIT 3

I am also adding the full explain analyze for the tqo queries I mentioned in my initial message

explain analyze select *
from satelliteproduct
where supplier_id = 226
and supplierproduct_id IN ('123', '234');
                                                                     QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------------------------------
 Index Scan using unq_satelliteproduct_0 on satelliteproduct  (cost=0.69..2.71 rows=1 width=2593) (actual time=11781.933..11781.935 rows=0 loops=1)
   Index Cond: (supplier_id = 226)
   Filter: ((supplierproduct_id)::text = ANY ('{123,234}'::text[]))
   Rows Removed by Filter: 2767533
 Planning Time: 0.247 ms
 Execution Time: 11808.777 ms
(6 rows)


explain analyze select *
from satelliteproduct
where supplier_id = 5129
and supplierproduct_id IN ('123', '234');
                                                                 QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------------------------
 Index Scan using unq_satelliteproduct_0 on satelliteproduct  (cost=0.69..4.41 rows=1 width=2593) (actual time=4.546..4.547 rows=0 loops=1)
   Index Cond: ((supplier_id = 5129) AND ((supplierproduct_id)::text = ANY ('{123,234}'::text[])))
 Planning Time: 0.215 ms
 Execution Time: 4.590 ms
(4 rows)

Small update. I reindexed all my indexes as they were quite bloated. Didn't change anything unfortunately with the queries.

9
  • 1
    this question is not geo related, maybe you move it to another forum
    – Jakob Miksch
    2 days ago
  • 2
    Have you attempted dropping and rebuilding the indices? Perhaps the index did finish building correctly before you shutdown, and its cross reference index is incomplete with 226?
    – RomaH
    2 days ago
  • 2
    For performance questions, please provide information as instructed here: dba.stackexchange.com/tags/postgresql-performance/info Should get clear as soon as we have that. 2 days ago
  • 5
    Neither of those two plans shows a Seq Scan. When you post a plan, make sure you preserve the indention as that is vital to understanding the plan. You should also show the complete plan, not only the parts that you think are important. To complete the picture, please also edit your question and add the create table and create index statements. 2 days ago
  • 1
    In addition to ahwnn request, what is the expected and actual number of rows with supplier_id = 226, leaving aside the other restriction?
    – jjanes
    2 days ago

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Browse other questions tagged or ask your own question.