Slow queries after db upgrade to 9.6

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hi,

  We recently upgraded our database from 9.1 to 9.6. We are seeing some
unusual slow queries after the upgrade.
Sometimes the queries are faster after vacuum analyze, but not consistent.
We tried with different settings of random_page_cost, work_mem,
effective_cache_size but the query results are the same. I am trying to
understand if changing the queries/indexes would give us better
performance. Please provide your suggestions. Below is our table,index
definition. 

Table : cm_ci_relations

       Column        |            Type             |       Modifiers
 | Storage  | Stats target | Description
---------------------+-----------------------------+-----------------------
-+----------+--------------+-------------
 ci_relation_id      | bigint                      | not null
 | plain    |              |
 ns_id               | bigint                      | not null
 | plain    | 200          |
 from_ci_id          | bigint                      | not null
 | plain    |              |
 relation_goid       | character varying(256)      | not null
 | extended |              |
 relation_id         | integer                     | not null
 | plain    |              |
 to_ci_id            | bigint                      | not null
 | plain    |              |
 ci_state_id         | integer                     | not null
 | plain    |              |
 last_applied_rfc_id | bigint                      |
 | plain    |              |
 comments            | character varying(2000)     |
 | extended |              |
 created_by          | character varying(200)      |
 | extended |              |
 update_by           | character varying(200)      |
 | extended |              |
 created             | timestamp without time zone | not null default
now() | plain    |              |
 updated             | timestamp without time zone | not null default
now() | plain    |              |
Indexes:
    "cm_ci_relations_pk" PRIMARY KEY, btree (ci_relation_id)
    "cm_ci_relations_goid_idx" UNIQUE, btree (relation_goid)
    "cm_ci_relations_uniq_idx" UNIQUE, btree (from_ci_id, relation_id,
to_ci_id)
    "cm_ci_relations_fromci_idx" btree (from_ci_id)
    "cm_ci_relations_ns_idx" btree (ns_id)
    "cm_ci_relations_r_ns_idx" btree (relation_id, ns_id)
    "cm_ci_relations_toci_idx" btree (to_ci_id)


Table : ns_namespaces

 Column  |            Type             |       Modifiers        | Storage
| Stats target | Description
---------+-----------------------------+------------------------+----------
+--------------+-------------
 ns_id   | bigint                      | not null               | plain
|              |
 ns_path | character varying(200)      | not null               | extended
| 300          |
 created | timestamp without time zone | not null default now() | plain
|              |
Indexes:
    "ns_namespaces_pk" PRIMARY KEY, btree (ns_id)
    "ns_namespaces_ak" UNIQUE, btree (ns_path)
    "ns_namespaces_vpo" btree (ns_path varchar_pattern_ops)


Table : cm_ci

       Column        |            Type             |       Modifiers
 | Storage  | Stats target | Description
---------------------+-----------------------------+-----------------------
-+----------+--------------+-------------
 ci_id               | bigint                      | not null
 | plain    |              |
 ns_id               | bigint                      | not null
 | plain    |              |
 class_id            | integer                     | not null
 | plain    |              |
 ci_name             | character varying(200)      | not null
 | extended |              |
 ci_goid             | character varying(256)      | not null
 | extended |              |
 comments            | character varying(2000)     |
 | extended |              |
 ci_state_id         | integer                     | not null
 | plain    |              |
 last_applied_rfc_id | bigint                      |
 | plain    |              |
 created_by          | character varying(200)      |
 | extended |              |
 updated_by          | character varying(200)      |
 | extended |              |
 created             | timestamp without time zone | not null default
now() | plain    |              |
 updated             | timestamp without time zone | not null default
now() | plain    |              |
Indexes:
    "cm_ci_pk" PRIMARY KEY, btree (ci_id)
    "cm_ci_3cols_idx" UNIQUE, btree (ns_id, class_id, ci_name)
    "df_ci_goid_idx" UNIQUE, btree (ci_goid)
    "cm_ci_cl_idx" btree (class_id)
    "cm_ci_ns_idx" btree (ns_id)


Table : md_relations

       Column        |            Type             |       Modifiers
 | Storage  | Stats target | Description
---------------------+-----------------------------+-----------------------
-+----------+--------------+-------------
 relation_id         | integer                     | not null
 | plain    |              |
 relation_name       | character varying(200)      | not null
 | extended |              |
 short_relation_name | character varying(200)      | not null
 | extended |              |
 description         | text                        | not null
 | extended |              |
 created             | timestamp without time zone | not null default
now() | plain    |              |
Indexes:
    "md_relations_pk" PRIMARY KEY, btree (relation_id)
    "md_relations_rln_idx" UNIQUE, btree (relation_name)
    "md_relations_srn_idx" btree (short_relation_name)



Table : md_classes
                                           Table "kloopzcm.md_classes"
      Column      |            Type             |       Modifiers        |
Storage  | Stats target | Description
------------------+-----------------------------+------------------------+-
---------+--------------+-------------
 class_id         | integer                     | not null               |
plain    |              |
 class_name       | character varying(200)      | not null               |
extended |              |
 short_class_name | character varying(200)      | not null               |
extended |              |
 super_class_id   | integer                     |                        |
plain    |              |
 is_namespace     | boolean                     | not null               |
plain    |              |
 flags            | integer                     | not null default 0     |
plain    |              |
 impl             | character varying(200)      |                        |
extended |              |
 access_level     | character varying(200)      |                        |
extended |              |
 description      | text                        |                        |
extended |              |
 format           | text                        |                        |
extended |              |
 created          | timestamp without time zone | not null default now() |
plain    |              |
Indexes:
    "md_classes_pk" PRIMARY KEY, btree (class_id)
    "md_classes_cln_idx" UNIQUE, btree (class_name)
    "md_classes_comp_names_idx" btree (class_name, short_class_name)
    "md_classes_scln_idx" btree (short_class_name)



Table : cm_ci_state

   Column    |         Type          | Modifiers | Storage  | Stats target
| Description
-------------+-----------------------+-----------+----------+--------------
+-------------
 ci_state_id | integer               | not null  | plain    |
|
 state_name  | character varying(64) | not null  | extended |
|
Indexes:
    "cm_ci_state_pk" PRIMARY KEY, btree (ci_state_id)



The below query has been really slow after the upgrade, the explain plan
shows that it uses the cm_ci_relations_fromci_idx index on the
cm_ci_relations table. But when another set of parameters are used for the
ns_path the query plan is better. In general I expect the ns_namespaces,
md_relations being queried first and then the results are further used on
the cm_ci_relations_r_ns_idx index (cm_ci_relations table) and then cm_ci
table. That would filter out a lot of records and will be much faster.

Table Data
----------
The ns_namespaces table contains data like a folder structure and can go
upto five levels separated by slash
/f1/f2/f3/f4/f5
/f1/f2/a1
/f1/f2/b1
/f1/c1
/g1/b1

There would be a lot of duplicates matching the beginning section of the
path.

cm_ci is the instances table with around 3 million records;
cm_ci_relations is the relations between instances table, with around 7.5
million records. this table is the largest in this query.
md_classes contains around 2k records
md_relations contains around 100+ records

Its not that the longer the ns_path parameter provided, the query is
faster. In some cases where the ns_path parameter is very much focused
like (/a/b/c/d/e) with different relation names and class names the query
was still slow as the planner was not using the best possible index
cm_ci_relations_r_ns_idx.


slow performing query:

explain (buffers, analyze) select
          cir.ci_relation_id as ciRelationId,
          cir.ns_id as nsId,
          ns.ns_path as nsPath,
          cir.from_ci_id as fromCiId,
          cir.relation_goid as relationGoid,
          cir.relation_id as relationId,
          mdr.relation_name as relationName,
          cir.to_ci_id toCiId,
          cir.ci_state_id as relationStateId,
          cis.state_name as relationState,
          cir.last_applied_rfc_id as lastAppliedRfcId,
          cir.comments,
               cir.created,
          cir.updated
  from cm_ci_relations cir, md_relations mdr, cm_ci_state cis, cm_ci
from_ci, md_classes from_mdc, cm_ci to_ci, md_classes to_mdc,
ns_namespaces ns
  where (ns.ns_path like '/test1/%' or ns.ns_path = '/test1')
    and cir.ns_id = ns.ns_id
    and cir.ci_state_id = cis.ci_state_id
    and cir.relation_id = mdr.relation_id
    and (mdr.relation_name = 'base.DeployedTo')
    and cir.from_ci_id = from_ci.ci_id
    and from_ci.class_id = from_mdc.class_id
    and ( from_mdc.class_name = 'bom.Compute')
    and cir.to_ci_id = to_ci.ci_id
    and to_ci.class_id = to_mdc.class_id;


below is the explain plan for this query
                   
             QUERY PLAN

---------------------------------------------------------------------------
-----------------------------------------------------------------
-----------------------------------------------
 Nested Loop  (cost=139.97..18932.15 rows=1 width=288) (actual
time=63.741..7213.251 rows=276 loops=1)
   Buffers: shared hit=552715 read=6114
   ->  Nested Loop  (cost=139.69..18931.84 rows=1 width=292) (actual
time=63.675..7211.745 rows=276 loops=1)
         Buffers: shared hit=552162 read=6114
         ->  Nested Loop  (cost=139.26..18931.35 rows=1 width=288) (actual
time=63.646..7206.066 rows=276 loops=1)
               Buffers: shared hit=551058 read=6114
               ->  Nested Loop  (cost=139.12..18931.19 rows=1 width=277)
(actual time=63.637..7199.116 rows=276 loops=1)
                     Buffers: shared hit=550506 read=6114
                     ->  Nested Loop  (cost=138.70..18919.38 rows=26
width=228) (actual time=58.446..6620.992 rows=62689 loops=1)
                           Join Filter: (cir.relation_id = mdr.relation_id)
                           Rows Removed by Join Filter: 125384
                           Buffers: shared hit=299270 read=6114
                           ->  Seq Scan on md_relations mdr
(cost=0.00..7.59 rows=1 width=22) (actual time=0.017..0.060 rows=1 loops=1)
                                 Filter: ((relation_name)::text =
'base.DeployedTo'::text)
                                 Rows Removed by Filter: 126
                                 Buffers: shared hit=6
                           ->  Nested Loop  (cost=138.70..18869.86
rows=3355 width=210) (actual time=58.418..6551.520 rows=188073 loops=1)
                                 Buffers: shared hit=299264 read=6114
                                 ->  Nested Loop  (cost=138.27..17306.08
rows=1271 width=8) (actual time=58.367..1012.918 rows=62710 loops=1
)
                                       Buffers: shared hit=28631
                                       ->  Index Scan using
md_classes_comp_names_idx on md_classes from_mdc  (cost=0.28..8.30 rows=1
width=
4) (actual time=0.031..0.037 rows=1 loops=1)
                                             Index Cond:
((class_name)::text = 'bom.Compute'::text)
                                             Buffers: shared hit=3
                                       ->  Bitmap Heap Scan on cm_ci
from_ci  (cost=137.99..17238.99 rows=5879 width=12) (actual time=58.332
..980.258 rows=62710 loops=1)
                                             Recheck Cond: (class_id =
from_mdc.class_id)
                                             Heap Blocks: exact=28001
                                             Buffers: shared hit=28628
                                             ->  Bitmap Index Scan on
cm_ci_cl_idx  (cost=0.00..136.52 rows=5879 width=0) (actual time=52.52
0..52.520 rows=63497 loops=1)
                                                   Index Cond: (class_id =
from_mdc.class_id)
                                                   Buffers: shared hit=627
                                 ->  Index Scan using
cm_ci_relations_fromci_idx on cm_ci_relations cir  (cost=0.43..1.07
rows=16 width=210)
 (actual time=0.067..0.084 rows=3 loops=62710)
                                       Index Cond: (from_ci_id =
from_ci.ci_id)
                                       Buffers: shared hit=270633 read=6114
                     ->  Index Scan using ns_namespaces_pk on
ns_namespaces ns  (cost=0.42..0.44 rows=1 width=57) (actual
time=0.008..0.008
rows=0 loops=62689)
                           Index Cond: (ns_id = cir.ns_id)
                           Filter: (((ns_path)::text ~~ '/test1/%'::text)
OR ((ns_path)::text = '/test1'::text))
                           Rows Removed by Filter: 1
                           Buffers: shared hit=251236
               ->  Index Scan using cm_ci_state_pk on cm_ci_state cis
(cost=0.13..0.15 rows=1 width=15) (actual time=0.002..0.003 rows=1 lo
ops=276)
                     Index Cond: (ci_state_id = cir.ci_state_id)
                     Buffers: shared hit=552
         ->  Index Scan using cm_ci_pk on cm_ci to_ci  (cost=0.43..0.48
rows=1 width=12) (actual time=0.015..0.016 rows=1 loops=276)
               Index Cond: (ci_id = cir.to_ci_id)
               Buffers: shared hit=1104
   ->  Index Only Scan using md_classes_pk on md_classes to_mdc
(cost=0.28..0.30 rows=1 width=4) (actual time=0.003..0.004 rows=1 loops=276
)
         Index Cond: (class_id = to_ci.class_id)
         Heap Fetches: 0
         Buffers: shared hit=553
 Planning time: 12.641 ms
 Execution time: 7214.707 ms



similar query with different parameters, this gets executed much faster

 explain (buffers, analyze) select
          cir.ci_relation_id as ciRelationId,
          cir.ns_id as nsId,
          ns.ns_path as nsPath,
          cir.from_ci_id as fromCiId,
          cir.relation_goid as relationGoid,
          cir.relation_id as relationId,
          mdr.relation_name as relationName,
          cir.to_ci_id toCiId,
          cir.ci_state_id as relationStateId,
          cis.state_name as relationState,
          cir.last_applied_rfc_id as lastAppliedRfcId,
          cir.comments,
               cir.created,
          cir.updated
  from cm_ci_relations cir, md_relations mdr, cm_ci_state cis, cm_ci
from_ci, md_classes from_mdc, cm_ci to_ci, md_classes to_mdc,
ns_namespaces ns
  where (ns.ns_path like '/test1/test2/%' or ns.ns_path = '/test1/test2')
    and cir.ns_id = ns.ns_id
    and cir.ci_state_id = cis.ci_state_id
    and cir.relation_id = mdr.relation_id
    and (mdr.relation_name = 'base.DeployedTo')
    and cir.from_ci_id = from_ci.ci_id
    and from_ci.class_id = from_mdc.class_id
    and ( from_mdc.class_name = 'bom.Compute')
    and cir.to_ci_id = to_ci.ci_id
    and to_ci.class_id = to_mdc.class_id;


                   
              QUERY PLAN

---------------------------------------------------------------------------
-----------------------------------------------------------------
--------------------------------------------------
 Nested Loop  (cost=10.72..479.62 rows=1 width=288) (actual
time=5.101..98.016 rows=114 loops=1)
   Buffers: shared hit=13321 read=31
   ->  Nested Loop  (cost=10.44..479.31 rows=1 width=292) (actual
time=5.068..97.647 rows=114 loops=1)
         Buffers: shared hit=13092 read=31
         ->  Nested Loop  (cost=10.01..478.82 rows=1 width=288) (actual
time=5.037..94.108 rows=114 loops=1)
               Join Filter: (cir.ci_state_id = cis.ci_state_id)
               Rows Removed by Join Filter: 456
               Buffers: shared hit=12636 read=31
               ->  Nested Loop  (cost=10.01..477.71 rows=1 width=277)
(actual time=5.030..93.568 rows=114 loops=1)
                     Buffers: shared hit=12522 read=31
                     ->  Nested Loop  (cost=9.73..475.54 rows=7 width=281)
(actual time=0.383..87.509 rows=1578 loops=1)
                           Buffers: shared hit=7788 read=31
                           ->  Nested Loop  (cost=9.30..472.10 rows=7
width=277) (actual time=0.362..53.412 rows=1578 loops=1)
                                 Buffers: shared hit=1475 read=26
                                 ->  Seq Scan on md_relations mdr
(cost=0.00..7.59 rows=1 width=22) (actual time=0.014..0.037 rows=1 loops=
1)
                                       Filter: ((relation_name)::text =
'base.DeployedTo'::text)
                                       Rows Removed by Filter: 126
                                       Buffers: shared hit=6
                                 ->  Nested Loop  (cost=9.30..463.63
rows=88 width=259) (actual time=0.333..52.719 rows=1578 loops=1)
                                       Buffers: shared hit=1469 read=26
                                       ->  Bitmap Heap Scan on
ns_namespaces ns  (cost=8.87..12.88 rows=22 width=57) (actual
time=0.202..0.4
51 rows=119 loops=1)
                                             Recheck Cond:
(((ns_path)::text ~~ '/test1/test2/%'::text) OR ((ns_path)::text =
'/test1/test2'
::text))
                                             Filter: (((ns_path)::text ~~
'/test1/test2/%'::text) OR ((ns_path)::text = '/test1/test2'::text
))
                                             Heap Blocks: exact=48
                                             Buffers: shared hit=54 read=1
                                             ->  BitmapOr
(cost=8.87..8.87 rows=1 width=0) (actual time=0.187..0.187 rows=0 loops=1)
                                                   Buffers: shared hit=6
read=1
                                                   ->  Bitmap Index Scan
on ns_namespaces_vpo  (cost=0.00..4.43 rows=1 width=0) (actual time
=0.181..0.181 rows=118 loops=1)
                                                         Index Cond:
(((ns_path)::text ~>=~ '/test1/test2/'::text) AND ((ns_path)::text ~<~
'/test1/test20'::text))
                                                         Buffers: shared
hit=3 read=1
                                                   ->  Bitmap Index Scan
on ns_namespaces_vpo  (cost=0.00..4.43 rows=1 width=0) (actual time
=0.004..0.004 rows=1 loops=1)
                                                         Index Cond:
((ns_path)::text = '/test1/test2'::text)
                                                         Buffers: shared
hit=3
                                       ->  Index Scan using
cm_ci_relations_r_ns_idx on cm_ci_relations cir  (cost=0.43..20.45 rows=4
width=
210) (actual time=0.010..0.429 rows=13 loops=119)
                                             Index Cond: ((relation_id =
mdr.relation_id) AND (ns_id = ns.ns_id))
                                             Buffers: shared hit=1415
read=25
                           ->  Index Scan using cm_ci_pk on cm_ci from_ci
(cost=0.43..0.48 rows=1 width=12) (actual time=0.020..0.020 rows=
1 loops=1578)
                                 Index Cond: (ci_id = cir.from_ci_id)
                                 Buffers: shared hit=6313 read=5
                     ->  Index Scan using md_classes_pk on md_classes
from_mdc  (cost=0.28..0.30 rows=1 width=4) (actual time=0.003..0.003 r
ows=0 loops=1578)
                           Index Cond: (class_id = from_ci.class_id)
                           Filter: ((class_name)::text =
'bom.Compute'::text)
                           Rows Removed by Filter: 1
                           Buffers: shared hit=4734
               ->  Seq Scan on cm_ci_state cis  (cost=0.00..1.05 rows=5
width=15) (actual time=0.001..0.002 rows=5 loops=114)
                     Buffers: shared hit=114
         ->  Index Scan using cm_ci_pk on cm_ci to_ci  (cost=0.43..0.48
rows=1 width=12) (actual time=0.030..0.030 rows=1 loops=114)
               Index Cond: (ci_id = cir.to_ci_id)
               Buffers: shared hit=456
   ->  Index Only Scan using md_classes_pk on md_classes to_mdc
(cost=0.28..0.30 rows=1 width=4) (actual time=0.002..0.002 rows=1 loops=114
)
         Index Cond: (class_id = to_ci.class_id)
         Heap Fetches: 0
         Buffers: shared hit=229
 Planning time: 8.468 ms
 Execution time: 98.223 ms




Thanks,
Bhaskar



-- 
Sent via pgsql-performance mailing list (pgsql-performance@xxxxxxxxxxxxxx)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance




[Postgresql General]     [Postgresql PHP]     [PHP Users]     [PHP Home]     [PHP on Windows]     [Kernel Newbies]     [PHP Classes]     [PHP Books]     [PHP Databases]     [Yosemite]

  Powered by Linux