pg.ddx.io pgsql-performance@postgresql.org mailing list archive
help / color / mirror / Atom feedPostgresql planning time too high
4+ messages / 4 participants
[nested] [flat]
* Postgresql planning time too high
@ 2019-11-22 11:21 Sterpu Victor <victor@caido.ro>
2019-11-22 11:35 ` RE: Postgresql planning time too high Fırat Güleç <firat.gulec@hepsijet.com>
0 siblings, 1 reply; 4+ messages in thread
From: Sterpu Victor @ 2019-11-22 11:21 UTC (permalink / raw)
To: pgsql-performance@lists.postgresql.org
Hello
I'm on a PostgreSQL 12.1 and I just restored a database from a backup.
When I run a query I get a big execution time: 5.482 ms
After running EXPLAIN ANALYZE I can see that the "Planning Time:
5165.742 ms" and the "Execution Time: 6.244 ms".
The database is new(no need to vacuum) and i'm the only one connected to
it. I use a single partition on the harddrive.
I also tried this on a postgresql 9.5 and the result was the same.
I'm not sure what to do to improve this situation.
The query and the explain is attached.
Thank you
"Limit (cost=67.86..67.87 rows=1 width=3972) (actual time=0.033..0.033 rows=0 loops=1)"
" -> Sort (cost=67.86..67.87 rows=1 width=3972) (actual time=0.032..0.032 rows=0 loops=1)"
" Sort Key: j1031101.validfrom DESC"
" Sort Method: quicksort Memory: 25kB"
" -> Nested Loop Left Join (cost=9.12..67.85 rows=1 width=3972) (actual time=0.022..0.022 rows=0 loops=1)"
" Join Filter: (j1034965.id = j1031074.id_persontype)"
" -> Nested Loop Left Join (cost=9.12..66.71 rows=1 width=3940) (actual time=0.022..0.022 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=8.98..66.14 rows=1 width=3936) (actual time=0.021..0.021 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=8.84..64.50 rows=1 width=3932) (actual time=0.021..0.021 rows=0 loops=1)"
" Join Filter: (j1033358.id = j1031074.id_drg_tip_cetatenie)"
" -> Nested Loop Left Join (cost=8.84..63.41 rows=1 width=3900) (actual time=0.021..0.021 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=8.70..62.84 rows=1 width=3384) (actual time=0.021..0.021 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=8.55..62.14 rows=1 width=3277) (actual time=0.021..0.021 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=8.40..60.49 rows=1 width=3270) (actual time=0.021..0.021 rows=0 loops=1)"
" Join Filter: (j1031737.id = j1031074.id_focg_stare_externare)"
" -> Nested Loop Left Join (cost=8.40..59.38 rows=1 width=3238) (actual time=0.021..0.021 rows=0 loops=1)"
" Join Filter: (j1031736.id = j1031074.id_focg_tip_externare)"
" -> Nested Loop Left Join (cost=8.40..58.29 rows=1 width=3206) (actual time=0.020..0.020 rows=0 loops=1)"
" Join Filter: (j1031100.id = j1031074.id_exceptie_bilet_internare)"
" -> Nested Loop Left Join (cost=8.40..57.09 rows=1 width=3174) (actual time=0.020..0.020 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=8.27..56.53 rows=1 width=3142) (actual time=0.019..0.019 rows=0 loops=1)"
" Join Filter: (j1031098.id = j1031074.id_focg_contract_modes)"
" -> Nested Loop Left Join (cost=8.27..55.46 rows=1 width=3110) (actual time=0.019..0.019 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=8.13..54.89 rows=1 width=3078) (actual time=0.019..0.019 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=7.99..54.33 rows=1 width=3050) (actual time=0.019..0.019 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=7.71..51.35 rows=1 width=3011) (actual time=0.019..0.019 rows=0 loops=1)"
" Join Filter: (j1031095.id = j1031074.id_focg_sursa_internare)"
" -> Nested Loop Left Join (cost=7.71..50.26 rows=1 width=2979) (actual time=0.019..0.019 rows=0 loops=1)"
" Join Filter: (j1031094.id = j1031074.id_cnp_mama)"
" -> Nested Loop Left Join (cost=7.71..49.24 rows=1 width=2969) (actual time=0.019..0.019 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=7.57..47.61 rows=1 width=2969) (actual time=0.019..0.019 rows=0 loops=1)"
" Join Filter: (j1031091.id = j1031074.id_focg_internat_prin)"
" -> Nested Loop Left Join (cost=7.57..46.52 rows=1 width=2937) (actual time=0.019..0.019 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=7.44..45.96 rows=1 width=2425) (actual time=0.018..0.018 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=7.31..45.40 rows=1 width=2397) (actual time=0.018..0.018 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=7.17..44.84 rows=1 width=1881) (actual time=0.017..0.017 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=7.02..43.19 rows=1 width=1874) (actual time=0.017..0.017 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=6.87..41.54 rows=1 width=1867) (actual time=0.017..0.017 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=6.73..40.98 rows=1 width=1839) (actual time=0.017..0.017 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=6.59..40.41 rows=1 width=1811) (actual time=0.017..0.017 rows=0 loops=1)"
" Join Filter: (j1031079.id = j1031074.idensuredstatus)"
" -> Nested Loop Left Join (cost=6.59..39.30 rows=1 width=1299) (actual time=0.017..0.017 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=6.46..38.74 rows=1 width=1271) (actual time=0.017..0.017 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=6.32..38.17 rows=1 width=1243) (actual time=0.017..0.017 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=6.19..37.62 rows=1 width=731) (actual time=0.016..0.016 rows=0 loops=1)"
" Join Filter: (j1031076.id = j1031075.idsex)"
" -> Nested Loop Left Join (cost=6.19..36.53 rows=1 width=219) (actual time=0.015..0.015 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=6.07..35.97 rows=1 width=186) (actual time=0.015..0.015 rows=0 loops=1)"
" Join Filter: (j1033360.validfrom > j1033359.validfrom)"
" Filter: (j1033360.id IS NULL)"
" -> Nested Loop (cost=5.91..34.33 rows=1 width=198) (actual time=0.015..0.015 rows=0 loops=1)"
" -> Nested Loop (cost=5.79..34.00 rows=2 width=182) (actual time=0.015..0.015 rows=0 loops=1)"
" Join Filter: (j1031074.id = j1033359.idfocg)"
" -> Nested Loop Left Join (cost=5.64..33.79 rows=1 width=166) (actual time=0.015..0.015 rows=0 loops=1)"
" Join Filter: (j1031102.validfrom < j1031101.validfrom)"
" Filter: (j1031102.id IS NULL)"
" -> Nested Loop Left Join (cost=5.48..32.14 rows=1 width=166) (actual time=0.015..0.015 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=5.35..31.98 rows=1 width=168) (actual time=0.015..0.015 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=5.06..30.94 rows=1 width=168) (actual time=0.015..0.015 rows=0 loops=1)"
" -> Nested Loop Anti Join (cost=4.91..29.30 rows=1 width=168) (actual time=0.015..0.015 rows=0 loops=1)"
" Join Filter: (j1037912.id < j1037911.id)"
" -> Nested Loop Left Join (cost=4.76..26.16 rows=1 width=168) (actual time=0.013..0.013 rows=0 loops=1)"
" -> Nested Loop (cost=4.61..24.51 rows=1 width=164) (actual time=0.013..0.013 rows=0 loops=1)"
" -> Nested Loop (cost=4.47..16.40 rows=41 width=32) (actual time=0.013..0.013 rows=0 loops=1)"
" -> Seq Scan on department j1033386 (cost=0.00..1.01 rows=1 width=24) (actual time=0.005..0.005 rows=1 loops=1)"
" -> Bitmap Heap Scan on focgdepartment j1031101 (cost=4.47..14.98 rows=41 width=16) (actual time=0.006..0.006 rows=0 loops=1)"
" Recheck Cond: (iddepartment = j1033386.id)"
" -> Bitmap Index Scan on foszdepartment_simple_index10 (cost=0.00..4.46 rows=41 width=0) (actual time=0.004..0.004 rows=0 loops=1)"
" Index Cond: (iddepartment = j1033386.id)"
" -> Index Scan using fosz_pkey on focg j1031074 (cost=0.14..0.19 rows=1 width=140) (never executed)"
" Index Cond: (id = j1031101.idfocg)"
" Filter: (id_stari_spitalizari = 1)"
" -> Index Scan using focg_procedures_uni on focg_procedures j1037911 (cost=0.15..1.64 rows=1 width=8) (never executed)"
" Index Cond: ((id_focg = j1031074.id) AND (este_ic_principala = 1))"
" -> Index Scan using focg_procedures_uni on focg_procedures j1037912 (cost=0.15..1.64 rows=1 width=8) (never executed)"
" Index Cond: ((id_focg = j1031074.id) AND (este_ic_principala = 1))"
" -> Index Scan using address_pkey on address j1037908 (cost=0.15..1.64 rows=1 width=8) (never executed)"
" Index Cond: (id = j1031074.id_address_domiciliu)"
" -> Index Scan using city_pkey on city j1037909 (cost=0.29..1.02 rows=1 width=8) (never executed)"
" Index Cond: (id = j1037908.idcity)"
" -> Index Scan using citytype_pkey on citytype j1037910 (cost=0.14..0.15 rows=1 width=6) (never executed)"
" Index Cond: (id = j1037909.citytype)"
" -> Index Scan using focgdepartment_uni2 on focgdepartment j1031102 (cost=0.15..1.64 rows=1 width=16) (never executed)"
" Index Cond: (idfocg = j1031074.id)"
" -> Index Scan using focgdepartment_uni2 on focgdepartment j1033359 (cost=0.15..0.20 rows=1 width=24) (never executed)"
" Index Cond: (idfocg = j1031101.idfocg)"
" -> Index Scan using department_pkey on department j1033387 (cost=0.12..0.15 rows=1 width=24) (never executed)"
" Index Cond: (id = j1033359.iddepartment)"
" -> Index Scan using focgdepartment_uni2 on focgdepartment j1033360 (cost=0.15..1.64 rows=1 width=16) (never executed)"
" Index Cond: (idfocg = j1031074.id)"
" -> Index Scan using person_pkey on person j1031075 (cost=0.12..0.54 rows=1 width=41) (never executed)"
" Index Cond: (id = j1031074.idpatient)"
" -> Seq Scan on sex j1031076 (cost=0.00..1.04 rows=4 width=520) (never executed)"
" -> Index Scan using ensuredstatustype_pkey on ensuredstatustype j1031078 (cost=0.13..0.55 rows=1 width=520) (never executed)"
" Index Cond: (id = j1031074.idensuredstatustype)"
" -> Index Scan using foszinterntype_pkey on focginterntype j1031082 (cost=0.14..0.55 rows=1 width=36) (never executed)"
" Index Cond: (id = j1031074.id_focg_tip_internare)"
" -> Index Scan using foszinterncrit_pkey on focginterncrit j1031083 (cost=0.14..0.55 rows=1 width=36) (never executed)"
" Index Cond: (id = j1031074.id_focg_criteriu_internare)"
" -> Seq Scan on ensuredstatus j1031079 (cost=0.00..1.05 rows=5 width=520) (never executed)"
" -> Index Scan using org_units_pkey on org_units j1031080 (cost=0.14..0.56 rows=1 width=36) (never executed)"
" Index Cond: (id = j1031074.id_org_unit)"
" -> Index Scan using personstate_pkey on personstate j1031081 (cost=0.14..0.55 rows=1 width=36) (never executed)"
" Index Cond: (id = j1031074.id_categorie_asigurat)"
" -> Index Scan using physicians_pkey on physicians j1031084 (cost=0.15..1.64 rows=1 width=15) (never executed)"
" Index Cond: (id = j1031074.idphysiciancurrent)"
" -> Index Scan using physicians_pkey on physicians j1031087 (cost=0.15..1.64 rows=1 width=11) (never executed)"
" Index Cond: (id = j1031074.idphysician_madeby)"
" -> Index Scan using proffession_pkey on proffession j1031088 (cost=0.13..0.55 rows=1 width=520) (never executed)"
" Index Cond: (id = j1031074.idproffesion)"
" -> Index Scan using focg_situatii_speciale_pkey on focg_situatii_speciale j1031090 (cost=0.13..0.55 rows=1 width=36) (never executed)"
" Index Cond: (id = j1031074.id_focg_situatii_speciale)"
" -> Index Scan using educationlevel_pkey on educationlevel j1031089 (cost=0.14..0.55 rows=1 width=520) (never executed)"
" Index Cond: (id = j1031074.id_education_level)"
" -> Seq Scan on focg_internat_prin j1031091 (cost=0.00..1.04 rows=4 width=36) (never executed)"
" -> Index Scan using fosz_pkey on focg j1031093 (cost=0.14..1.62 rows=1 width=8) (never executed)"
" Index Cond: (id = j1031074.id_focg)"
" -> Seq Scan on person j1031094 (cost=0.00..1.01 rows=1 width=18) (never executed)"
" -> Seq Scan on focg_sursa_internare j1031095 (cost=0.00..1.04 rows=4 width=36) (never executed)"
" -> Index Scan using icd10_pkey on icd10 j1031097 (cost=0.28..2.96 rows=1 width=43) (never executed)"
" Index Cond: (id = j1031074.id_icd10)"
" -> Index Scan using formulare_europene_pkey on formulare_europene j1031092 (cost=0.14..0.55 rows=1 width=36) (never executed)"
" Index Cond: (id = j1031074.id_formulare_europene)"
" -> Index Scan using diseasecategory_pkey on diseasecategory j1031096 (cost=0.14..0.56 rows=1 width=36) (never executed)"
" Index Cond: (id = j1031074.id_diseasecategory)"
" -> Seq Scan on focg_contract_modes j1031098 (cost=0.00..1.03 rows=3 width=36) (never executed)"
" -> Index Scan using focg_criterii_urgenta_pkey on focg_criterii_urgenta j1031099 (cost=0.14..0.55 rows=1 width=36) (never executed)"
" Index Cond: (id = j1031074.id_focg_criterii_urgenta)"
" -> Seq Scan on exceptie_bilet_internare j1031100 (cost=0.00..1.09 rows=9 width=36) (never executed)"
" -> Seq Scan on focg_tip_externare j1031736 (cost=0.00..1.04 rows=4 width=36) (never executed)"
" -> Seq Scan on focg_stare_externare j1031737 (cost=0.00..1.05 rows=5 width=36) (never executed)"
" -> Index Scan using physicians_pkey on physicians j1033295 (cost=0.15..1.64 rows=1 width=11) (never executed)"
" Index Cond: (id = j1031074.idphysician_surgeon)"
" -> Index Scan using hospital_release_statuses_pkey on hospital_release_statuses j1033299 (cost=0.14..0.69 rows=1 width=111) (never executed)"
" Index Cond: (id = j1031074.id_hospital_release_statuses)"
" -> Index Scan using citizenship_pkey on citizenship j1033304 (cost=0.14..0.56 rows=1 width=520) (never executed)"
" Index Cond: (id = j1031074.id_citizenship)"
" -> Seq Scan on drg_tip_cetatenie j1033358 (cost=0.00..1.04 rows=4 width=36) (never executed)"
" -> Index Scan using fupu_pkey on fupu j1034618 (cost=0.14..1.63 rows=1 width=8) (never executed)"
" Index Cond: (id = j1031074.id_fupu)"
" -> Index Scan using country_pkey on country j1034962 (cost=0.14..0.56 rows=1 width=8) (never executed)"
" Index Cond: (id = j1031074.id_country)"
" -> Seq Scan on persontype j1034965 (cost=0.00..1.06 rows=6 width=36) (never executed)"
"Planning time: 3769.727 ms"
"Execution time: 1.494 ms"
Attachments:
[text/plain] explain.txt (32.3K, ../../emd93eb533-aade-42ef-8609-2dccab1463d4@victor-pc/3-explain.txt)
download | inline:
"Limit (cost=67.86..67.87 rows=1 width=3972) (actual time=0.033..0.033 rows=0 loops=1)"
" -> Sort (cost=67.86..67.87 rows=1 width=3972) (actual time=0.032..0.032 rows=0 loops=1)"
" Sort Key: j1031101.validfrom DESC"
" Sort Method: quicksort Memory: 25kB"
" -> Nested Loop Left Join (cost=9.12..67.85 rows=1 width=3972) (actual time=0.022..0.022 rows=0 loops=1)"
" Join Filter: (j1034965.id = j1031074.id_persontype)"
" -> Nested Loop Left Join (cost=9.12..66.71 rows=1 width=3940) (actual time=0.022..0.022 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=8.98..66.14 rows=1 width=3936) (actual time=0.021..0.021 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=8.84..64.50 rows=1 width=3932) (actual time=0.021..0.021 rows=0 loops=1)"
" Join Filter: (j1033358.id = j1031074.id_drg_tip_cetatenie)"
" -> Nested Loop Left Join (cost=8.84..63.41 rows=1 width=3900) (actual time=0.021..0.021 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=8.70..62.84 rows=1 width=3384) (actual time=0.021..0.021 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=8.55..62.14 rows=1 width=3277) (actual time=0.021..0.021 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=8.40..60.49 rows=1 width=3270) (actual time=0.021..0.021 rows=0 loops=1)"
" Join Filter: (j1031737.id = j1031074.id_focg_stare_externare)"
" -> Nested Loop Left Join (cost=8.40..59.38 rows=1 width=3238) (actual time=0.021..0.021 rows=0 loops=1)"
" Join Filter: (j1031736.id = j1031074.id_focg_tip_externare)"
" -> Nested Loop Left Join (cost=8.40..58.29 rows=1 width=3206) (actual time=0.020..0.020 rows=0 loops=1)"
" Join Filter: (j1031100.id = j1031074.id_exceptie_bilet_internare)"
" -> Nested Loop Left Join (cost=8.40..57.09 rows=1 width=3174) (actual time=0.020..0.020 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=8.27..56.53 rows=1 width=3142) (actual time=0.019..0.019 rows=0 loops=1)"
" Join Filter: (j1031098.id = j1031074.id_focg_contract_modes)"
" -> Nested Loop Left Join (cost=8.27..55.46 rows=1 width=3110) (actual time=0.019..0.019 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=8.13..54.89 rows=1 width=3078) (actual time=0.019..0.019 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=7.99..54.33 rows=1 width=3050) (actual time=0.019..0.019 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=7.71..51.35 rows=1 width=3011) (actual time=0.019..0.019 rows=0 loops=1)"
" Join Filter: (j1031095.id = j1031074.id_focg_sursa_internare)"
" -> Nested Loop Left Join (cost=7.71..50.26 rows=1 width=2979) (actual time=0.019..0.019 rows=0 loops=1)"
" Join Filter: (j1031094.id = j1031074.id_cnp_mama)"
" -> Nested Loop Left Join (cost=7.71..49.24 rows=1 width=2969) (actual time=0.019..0.019 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=7.57..47.61 rows=1 width=2969) (actual time=0.019..0.019 rows=0 loops=1)"
" Join Filter: (j1031091.id = j1031074.id_focg_internat_prin)"
" -> Nested Loop Left Join (cost=7.57..46.52 rows=1 width=2937) (actual time=0.019..0.019 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=7.44..45.96 rows=1 width=2425) (actual time=0.018..0.018 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=7.31..45.40 rows=1 width=2397) (actual time=0.018..0.018 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=7.17..44.84 rows=1 width=1881) (actual time=0.017..0.017 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=7.02..43.19 rows=1 width=1874) (actual time=0.017..0.017 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=6.87..41.54 rows=1 width=1867) (actual time=0.017..0.017 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=6.73..40.98 rows=1 width=1839) (actual time=0.017..0.017 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=6.59..40.41 rows=1 width=1811) (actual time=0.017..0.017 rows=0 loops=1)"
" Join Filter: (j1031079.id = j1031074.idensuredstatus)"
" -> Nested Loop Left Join (cost=6.59..39.30 rows=1 width=1299) (actual time=0.017..0.017 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=6.46..38.74 rows=1 width=1271) (actual time=0.017..0.017 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=6.32..38.17 rows=1 width=1243) (actual time=0.017..0.017 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=6.19..37.62 rows=1 width=731) (actual time=0.016..0.016 rows=0 loops=1)"
" Join Filter: (j1031076.id = j1031075.idsex)"
" -> Nested Loop Left Join (cost=6.19..36.53 rows=1 width=219) (actual time=0.015..0.015 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=6.07..35.97 rows=1 width=186) (actual time=0.015..0.015 rows=0 loops=1)"
" Join Filter: (j1033360.validfrom > j1033359.validfrom)"
" Filter: (j1033360.id IS NULL)"
" -> Nested Loop (cost=5.91..34.33 rows=1 width=198) (actual time=0.015..0.015 rows=0 loops=1)"
" -> Nested Loop (cost=5.79..34.00 rows=2 width=182) (actual time=0.015..0.015 rows=0 loops=1)"
" Join Filter: (j1031074.id = j1033359.idfocg)"
" -> Nested Loop Left Join (cost=5.64..33.79 rows=1 width=166) (actual time=0.015..0.015 rows=0 loops=1)"
" Join Filter: (j1031102.validfrom < j1031101.validfrom)"
" Filter: (j1031102.id IS NULL)"
" -> Nested Loop Left Join (cost=5.48..32.14 rows=1 width=166) (actual time=0.015..0.015 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=5.35..31.98 rows=1 width=168) (actual time=0.015..0.015 rows=0 loops=1)"
" -> Nested Loop Left Join (cost=5.06..30.94 rows=1 width=168) (actual time=0.015..0.015 rows=0 loops=1)"
" -> Nested Loop Anti Join (cost=4.91..29.30 rows=1 width=168) (actual time=0.015..0.015 rows=0 loops=1)"
" Join Filter: (j1037912.id < j1037911.id)"
" -> Nested Loop Left Join (cost=4.76..26.16 rows=1 width=168) (actual time=0.013..0.013 rows=0 loops=1)"
" -> Nested Loop (cost=4.61..24.51 rows=1 width=164) (actual time=0.013..0.013 rows=0 loops=1)"
" -> Nested Loop (cost=4.47..16.40 rows=41 width=32) (actual time=0.013..0.013 rows=0 loops=1)"
" -> Seq Scan on department j1033386 (cost=0.00..1.01 rows=1 width=24) (actual time=0.005..0.005 rows=1 loops=1)"
" -> Bitmap Heap Scan on focgdepartment j1031101 (cost=4.47..14.98 rows=41 width=16) (actual time=0.006..0.006 rows=0 loops=1)"
" Recheck Cond: (iddepartment = j1033386.id)"
" -> Bitmap Index Scan on foszdepartment_simple_index10 (cost=0.00..4.46 rows=41 width=0) (actual time=0.004..0.004 rows=0 loops=1)"
" Index Cond: (iddepartment = j1033386.id)"
" -> Index Scan using fosz_pkey on focg j1031074 (cost=0.14..0.19 rows=1 width=140) (never executed)"
" Index Cond: (id = j1031101.idfocg)"
" Filter: (id_stari_spitalizari = 1)"
" -> Index Scan using focg_procedures_uni on focg_procedures j1037911 (cost=0.15..1.64 rows=1 width=8) (never executed)"
" Index Cond: ((id_focg = j1031074.id) AND (este_ic_principala = 1))"
" -> Index Scan using focg_procedures_uni on focg_procedures j1037912 (cost=0.15..1.64 rows=1 width=8) (never executed)"
" Index Cond: ((id_focg = j1031074.id) AND (este_ic_principala = 1))"
" -> Index Scan using address_pkey on address j1037908 (cost=0.15..1.64 rows=1 width=8) (never executed)"
" Index Cond: (id = j1031074.id_address_domiciliu)"
" -> Index Scan using city_pkey on city j1037909 (cost=0.29..1.02 rows=1 width=8) (never executed)"
" Index Cond: (id = j1037908.idcity)"
" -> Index Scan using citytype_pkey on citytype j1037910 (cost=0.14..0.15 rows=1 width=6) (never executed)"
" Index Cond: (id = j1037909.citytype)"
" -> Index Scan using focgdepartment_uni2 on focgdepartment j1031102 (cost=0.15..1.64 rows=1 width=16) (never executed)"
" Index Cond: (idfocg = j1031074.id)"
" -> Index Scan using focgdepartment_uni2 on focgdepartment j1033359 (cost=0.15..0.20 rows=1 width=24) (never executed)"
" Index Cond: (idfocg = j1031101.idfocg)"
" -> Index Scan using department_pkey on department j1033387 (cost=0.12..0.15 rows=1 width=24) (never executed)"
" Index Cond: (id = j1033359.iddepartment)"
" -> Index Scan using focgdepartment_uni2 on focgdepartment j1033360 (cost=0.15..1.64 rows=1 width=16) (never executed)"
" Index Cond: (idfocg = j1031074.id)"
" -> Index Scan using person_pkey on person j1031075 (cost=0.12..0.54 rows=1 width=41) (never executed)"
" Index Cond: (id = j1031074.idpatient)"
" -> Seq Scan on sex j1031076 (cost=0.00..1.04 rows=4 width=520) (never executed)"
" -> Index Scan using ensuredstatustype_pkey on ensuredstatustype j1031078 (cost=0.13..0.55 rows=1 width=520) (never executed)"
" Index Cond: (id = j1031074.idensuredstatustype)"
" -> Index Scan using foszinterntype_pkey on focginterntype j1031082 (cost=0.14..0.55 rows=1 width=36) (never executed)"
" Index Cond: (id = j1031074.id_focg_tip_internare)"
" -> Index Scan using foszinterncrit_pkey on focginterncrit j1031083 (cost=0.14..0.55 rows=1 width=36) (never executed)"
" Index Cond: (id = j1031074.id_focg_criteriu_internare)"
" -> Seq Scan on ensuredstatus j1031079 (cost=0.00..1.05 rows=5 width=520) (never executed)"
" -> Index Scan using org_units_pkey on org_units j1031080 (cost=0.14..0.56 rows=1 width=36) (never executed)"
" Index Cond: (id = j1031074.id_org_unit)"
" -> Index Scan using personstate_pkey on personstate j1031081 (cost=0.14..0.55 rows=1 width=36) (never executed)"
" Index Cond: (id = j1031074.id_categorie_asigurat)"
" -> Index Scan using physicians_pkey on physicians j1031084 (cost=0.15..1.64 rows=1 width=15) (never executed)"
" Index Cond: (id = j1031074.idphysiciancurrent)"
" -> Index Scan using physicians_pkey on physicians j1031087 (cost=0.15..1.64 rows=1 width=11) (never executed)"
" Index Cond: (id = j1031074.idphysician_madeby)"
" -> Index Scan using proffession_pkey on proffession j1031088 (cost=0.13..0.55 rows=1 width=520) (never executed)"
" Index Cond: (id = j1031074.idproffesion)"
" -> Index Scan using focg_situatii_speciale_pkey on focg_situatii_speciale j1031090 (cost=0.13..0.55 rows=1 width=36) (never executed)"
" Index Cond: (id = j1031074.id_focg_situatii_speciale)"
" -> Index Scan using educationlevel_pkey on educationlevel j1031089 (cost=0.14..0.55 rows=1 width=520) (never executed)"
" Index Cond: (id = j1031074.id_education_level)"
" -> Seq Scan on focg_internat_prin j1031091 (cost=0.00..1.04 rows=4 width=36) (never executed)"
" -> Index Scan using fosz_pkey on focg j1031093 (cost=0.14..1.62 rows=1 width=8) (never executed)"
" Index Cond: (id = j1031074.id_focg)"
" -> Seq Scan on person j1031094 (cost=0.00..1.01 rows=1 width=18) (never executed)"
" -> Seq Scan on focg_sursa_internare j1031095 (cost=0.00..1.04 rows=4 width=36) (never executed)"
" -> Index Scan using icd10_pkey on icd10 j1031097 (cost=0.28..2.96 rows=1 width=43) (never executed)"
" Index Cond: (id = j1031074.id_icd10)"
" -> Index Scan using formulare_europene_pkey on formulare_europene j1031092 (cost=0.14..0.55 rows=1 width=36) (never executed)"
" Index Cond: (id = j1031074.id_formulare_europene)"
" -> Index Scan using diseasecategory_pkey on diseasecategory j1031096 (cost=0.14..0.56 rows=1 width=36) (never executed)"
" Index Cond: (id = j1031074.id_diseasecategory)"
" -> Seq Scan on focg_contract_modes j1031098 (cost=0.00..1.03 rows=3 width=36) (never executed)"
" -> Index Scan using focg_criterii_urgenta_pkey on focg_criterii_urgenta j1031099 (cost=0.14..0.55 rows=1 width=36) (never executed)"
" Index Cond: (id = j1031074.id_focg_criterii_urgenta)"
" -> Seq Scan on exceptie_bilet_internare j1031100 (cost=0.00..1.09 rows=9 width=36) (never executed)"
" -> Seq Scan on focg_tip_externare j1031736 (cost=0.00..1.04 rows=4 width=36) (never executed)"
" -> Seq Scan on focg_stare_externare j1031737 (cost=0.00..1.05 rows=5 width=36) (never executed)"
" -> Index Scan using physicians_pkey on physicians j1033295 (cost=0.15..1.64 rows=1 width=11) (never executed)"
" Index Cond: (id = j1031074.idphysician_surgeon)"
" -> Index Scan using hospital_release_statuses_pkey on hospital_release_statuses j1033299 (cost=0.14..0.69 rows=1 width=111) (never executed)"
" Index Cond: (id = j1031074.id_hospital_release_statuses)"
" -> Index Scan using citizenship_pkey on citizenship j1033304 (cost=0.14..0.56 rows=1 width=520) (never executed)"
" Index Cond: (id = j1031074.id_citizenship)"
" -> Seq Scan on drg_tip_cetatenie j1033358 (cost=0.00..1.04 rows=4 width=36) (never executed)"
" -> Index Scan using fupu_pkey on fupu j1034618 (cost=0.14..1.63 rows=1 width=8) (never executed)"
" Index Cond: (id = j1031074.id_fupu)"
" -> Index Scan using country_pkey on country j1034962 (cost=0.14..0.56 rows=1 width=8) (never executed)"
" Index Cond: (id = j1031074.id_country)"
" -> Seq Scan on persontype j1034965 (cost=0.00..1.06 rows=6 width=36) (never executed)"
"Planning time: 3769.727 ms"
"Execution time: 1.494 ms"
[application/octet-stream] query.sql (6.6K, ../../emd93eb533-aade-42ef-8609-2dccab1463d4@victor-pc/4-query.sql)
download
^ permalink raw reply [nested|flat] 4+ messages in thread
* RE: Postgresql planning time too high
2019-11-22 11:21 Postgresql planning time too high Sterpu Victor <victor@caido.ro>
@ 2019-11-22 11:35 ` Fırat Güleç <firat.gulec@hepsijet.com>
2019-11-22 12:22 ` Re: Postgresql planning time too high Luís Roberto Weck <luisroberto@siscobra.com.br>
2019-11-22 19:36 ` Re: Postgresql planning time too high Tomas Vondra <tomas.vondra@2ndquadrant.com>
0 siblings, 2 replies; 4+ messages in thread
From: Fırat Güleç @ 2019-11-22 11:35 UTC (permalink / raw)
To: Sterpu Victor <victor@caido.ro>; +Cc: pgsql-performance@lists.postgresql.org
Hello Sterpu,
First, please run vaccum for your Postgresql DB.
No rows returned from your query. Could you double check your query
criteria.
After that could you send explain analyze again .
Regards,
*FIRAT GÜLEÇ*
Infrastructure & Database Operations Manager
firat.gulec@hepsijet.com
*M:* 0 532 210 57 18
İnönü Mh. Mimar Sinan Cd. No:3 Güzeller Org.San.Bölg. GEBZE / KOCAELİ
[image: image.png]
*From:* Sterpu Victor <victor@caido.ro>
*Sent:* Friday, November 22, 2019 2:21 PM
*To:* pgsql-performance@lists.postgresql.org
*Subject:* Postgresql planning time too high
Hello
I'm on a PostgreSQL 12.1 and I just restored a database from a backup.
When I run a query I get a big execution time: 5.482 ms
After running EXPLAIN ANALYZE I can see that the "Planning Time: 5165.742
ms" and the "Execution Time: 6.244 ms".
The database is new(no need to vacuum) and i'm the only one connected to
it. I use a single partition on the harddrive.
I also tried this on a postgresql 9.5 and the result was the same.
I'm not sure what to do to improve this situation.
The query and the explain is attached.
Thank you
Attachments:
[image/png] image002.png (15.8K, ../../7ca4228bd9ea8ee1b119123679f340ff@mail.gmail.com/3-image002.png)
download | view image
^ permalink raw reply [nested|flat] 4+ messages in thread
* Re: Postgresql planning time too high
2019-11-22 11:21 Postgresql planning time too high Sterpu Victor <victor@caido.ro>
2019-11-22 11:35 ` RE: Postgresql planning time too high Fırat Güleç <firat.gulec@hepsijet.com>
@ 2019-11-22 12:22 ` Luís Roberto Weck <luisroberto@siscobra.com.br>
1 sibling, 0 replies; 4+ messages in thread
From: Luís Roberto Weck @ 2019-11-22 12:22 UTC (permalink / raw)
To: victor@caido.ro; +Cc: pgsql-performance@lists.postgresql.org
Em 22/11/2019 08:46, Sterpu Victor escreveu:
> I did runned "VACCUM FULL" followed by "VACUUM" but no difference.
>
> ------ Original Message ------
> From: "Fırat Güleç" <firat.gulec@hepsijet.com
> <mailto:firat.gulec@hepsijet.com>>
> To: "Sterpu Victor" <victor@caido.ro <mailto:victor@caido.ro>>
> Cc: pgsql-performance@lists.postgresql.org
> <mailto:pgsql-performance@lists.postgresql.org>
> Sent: 2019-11-22 1:35:15 PM
> Subject: RE: Postgresql planning time too high
>
>> Hello Sterpu,
>>
>> First, please run vaccum for your Postgresql DB.
>>
>> No rows returned from your query. Could you double check your query
>> criteria.
>>
>> After that could you send explain analyze again .
>>
>> Regards,
>>
>> *FIRAT GÜLEÇ***
>> Infrastructure & Database Operations Manager
>> firat.gulec@hepsijet.com <mailto:firat.gulec@hepsijet.com>
>>
>> *M:*0 532 210 57 18
>> İnönü Mh. Mimar Sinan Cd. No:3 Güzeller Org.San.Bölg. GEBZE / KOCAELİ
>>
>> image.png
>>
>> *From:*Sterpu Victor <victor@caido.ro <mailto:victor@caido.ro>>
>> *Sent:* Friday, November 22, 2019 2:21 PM
>> *To:* pgsql-performance@lists.postgresql.org
>> <mailto:pgsql-performance@lists.postgresql.org>
>> *Subject:* Postgresql planning time too high
>>
>> Hello
>>
>> I'm on a PostgreSQL 12.1 and I just restored a database from a backup.
>>
>> When I run a query I get a big execution time: 5.482 ms
>>
>> After running EXPLAIN ANALYZE I can see that the "Planning Time:
>> 5165.742 ms" and the "Execution Time: 6.244 ms".
>>
>> The database is new(no need to vacuum) and i'm the only one connected
>> to it. I use a single partition on the harddrive.
>>
>> I also tried this on a postgresql 9.5 and the result was the same.
>>
>> I'm not sure what to do to improve this situation.
>>
>> The query and the explain is attached.
>>
>> Thank you
>>
Have you run the ANALYZE command to update your DB statistics?
Attachments:
[image/png] image002.png (10.3K, ../../a4120d74-48d6-b54c-4ede-4ef209bf2bbf@siscobra.com.br/3-image002.png)
download | view image
^ permalink raw reply [nested|flat] 4+ messages in thread
* Re: Postgresql planning time too high
2019-11-22 11:21 Postgresql planning time too high Sterpu Victor <victor@caido.ro>
2019-11-22 11:35 ` RE: Postgresql planning time too high Fırat Güleç <firat.gulec@hepsijet.com>
@ 2019-11-22 19:36 ` Tomas Vondra <tomas.vondra@2ndquadrant.com>
1 sibling, 0 replies; 4+ messages in thread
From: Tomas Vondra @ 2019-11-22 19:36 UTC (permalink / raw)
To: Sterpu Victor <victor@caido.ro>; +Cc: Fırat Güleç <firat.gulec@hepsijet.com>; pgsql-performance@lists.postgresql.org
On Fri, Nov 22, 2019 at 11:44:51AM +0000, Sterpu Victor wrote:
>No rows should be returned, DB is empty.
>I'm testing now on a empty DB trying to find out how to improve this.
>
I'm a bit puzzled why you're doinf tests on an empty database, when in
production it'll certainly contain data. I guess you're assuming that
this way you isolate planning time, which should remain about the same
even with data loaded, but I'm not entirely sure that's true - all this
planning is done with no statistics (histograms, MCV lists, ...) and
maybe it's forcing the planner to do more work? I wouldn't be surprised
if having those stats would allow the planner to take some shortcuts,
cutting the plannnig time down.
Not to mention that we don't know if the plan is actually any good, for
all what we know it might take 10 years on real data, making the
planning duration irrelevant.
Let's put that aside, though. Let's assume it's because of expensive
join order planning. I don't think you have a lot of options, here,
unfortunately.
One option is to try reducing the planner options that determine how
much effort should be spent on join planning, e.g. join_collapse_limit
and geqo_threshold. If this is the root cause, you might even rewrite
the query to use optimal join order and set join_collapse_limit=1.
You'll have to play with it.
The other option is using CTEs with materialization, with the same
effect, i.e. prevention of optimization across CTEs, reducing the
total effort.
>In this query I have 3 joins like this:
>
>SELECT t1.id, t2.valid_from
>FROM t1
>JOIN t2 ON (t1.id_t1 = t1.id)
>LEFT JOIN t3 ON (t3.id_t1 = t1.id AND t3.valid_from<t2.valid_from)
>WHERE t3.id IS NULL
>
>If I delete these 3 joins than the planning time goes down from 5.482
>ms to 754.708 ms but I'm not sure why this context is so demanding on
>the planner.
>I'm tryng now to make a materialized view that will allow me to stop
>using the syntax above.
>
>I reattached the same files, they should be fine like this.
>
It'd be useful to have something others can use to reproduce the issue,
and investigate locally. SQL script that creates the whole schema and
runs the query, for example.
What I'd like to see is a perf profile from the planning, so that we can
see where exactly is the bottleneck. Maybe there actually is a bug that
makes it muych more expensive than it should be, in some corner case?
regards
--
Tomas Vondra http://www.2ndQuadrant.com
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
^ permalink raw reply [nested|flat] 4+ messages in thread
end of thread, other threads:[~2019-11-22 19:36 UTC | newest]
Thread overview: 4+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2019-11-22 11:21 Postgresql planning time too high Sterpu Victor <victor@caido.ro>
2019-11-22 11:35 ` Fırat Güleç <firat.gulec@hepsijet.com>
2019-11-22 12:22 ` Luís Roberto Weck <luisroberto@siscobra.com.br>
2019-11-22 19:36 ` Tomas Vondra <tomas.vondra@2ndquadrant.com>
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox