Re: The query plan get all columns but I'm using only one column. - Mailing list pgsql-performance

From Moises Lopez
Subject Re: The query plan get all columns but I'm using only one column.
Date
Msg-id CAGro9RXPZP-NC7wpYzuWgEM8bm7o276wG7DEQt7nZtpDuk-GOw@mail.gmail.com
Whole thread Raw
In response to Re: The query plan get all columns but I'm using only one column.  (Michael Lewis <mlewis@entrata.com>)
List pgsql-performance
Hello,
Thanks for reply

I have 2 environments production and staging.

The pg_settings result for both environment is the same:
namesettingmin_valmax_valcontext
effective_cache_size3,145,72812,147,483,647user
shared_buffers1,048,576161,073,741,823postmaster
work_mem5,592642,147,483,647user

I have created a backup from production and restored it in staging.

For staging I have configured the following extra parameters:
# config for testing environment only
fsync=off
full_page_write=off
checkpoint_timeout=45min
synchronous_commit=off
autovacuum=off


For staging the query plans was:
[{'QUERY PLAN': 'Aggregate (cost=7433.20..7433.21 rows=1 width=8) (actual time=56.372..56.372 rows=1 loops=1)'},
 {'QUERY PLAN': ' Output: count(product_template.id)'},
 {'QUERY PLAN': ' Buffers: shared hit=3580'},
 {'QUERY PLAN': ' -> Hash Right Join (cost=3695.08..7349.06 rows=33656 width=4) (actual time=32.039..54.076 rows=33709 loops=1)'},
 {'QUERY PLAN': ' Output: product_template.id'},
 {'QUERY PLAN': ' Hash Cond: (ir_translation.res_id = product_template.id)'},
 {'QUERY PLAN': ' Buffers: shared hit=3580'},
 {'QUERY PLAN': ' -> Bitmap Heap Scan on public.ir_translation (cost=1128.80..4459.54 rows=24187 width=4) (actual time=6.143..18.122 rows=33293 loops=1)'},
 {'QUERY PLAN': ' Output: ir_translation.id, ir_translation.lang, ir_translation.src, ir_translation.type, ir_translation.res_id, ir_translation.value, ir_translation.name, ir_translation.module, ir_translation.state, ir_translation.comments'},
 {'QUERY PLAN': " Recheck Cond: (((ir_translation.name)::text = 'product.template,name'::text) AND ((ir_translation.lang)::text = 'es_CR'::text) AND ((ir_translation.type)::text = 'model'::text))"},
 {'QUERY PLAN': " Filter: (ir_translation.value <> ''::text)"},
 {'QUERY PLAN': ' Heap Blocks: exact=1632'},
 {'QUERY PLAN': ' Buffers: shared hit=1872'},
 {'QUERY PLAN': ' -> Bitmap Index Scan on ir_translation_ltn (cost=0.00..1122.76 rows=24187 width=0) (actual time=5.960..5.960 rows=33293 loops=1)'},
 {'QUERY PLAN': " Index Cond: (((ir_translation.name)::text = 'product.template,name'::text) AND ((ir_translation.lang)::text = 'es_CR'::text) AND ((ir_translation.type)::text = 'model'::text))"},
 {'QUERY PLAN': ' Buffers: shared hit=240'},
 {'QUERY PLAN': ' -> Hash (cost=2145.57..2145.57 rows=33656 width=4) (actual time=25.724..25.724 rows=33709 loops=1)'},
 {'QUERY PLAN': ' Output: product_template.id'},
 {'QUERY PLAN': ' Buckets: 65536 Batches: 1 Memory Usage: 1698kB'},
 {'QUERY PLAN': ' Buffers: shared hit=1708'},
 {'QUERY PLAN': ' -> Seq Scan on public.product_template (cost=0.00..2145.57 rows=33656 width=4) (actual time=0.015..19.301 rows=33709 loops=1)'},
 {'QUERY PLAN': ' Output: product_template.id'},
 {'QUERY PLAN': " Filter: (product_template.active AND ((product_template.type)::text = ANY ('{consu,product}'::text[])))"},
 {'QUERY PLAN': ' Rows Removed by Filter: 1297'},
 {'QUERY PLAN': ' Buffers: shared hit=1708'},
 {'QUERY PLAN': 'Planning time: 0.782 ms'},
 {'QUERY PLAN': 'Execution time: 56.441 ms'}]

For production the query plan was:
[{'QUERY PLAN': 'Aggregate (cost=2157.08..2157.09 rows=1 width=8) (actual time=53219.763..53219.763 rows=1 loops=1)'},
 {'QUERY PLAN': ' Output: count(product_template.id)'},
 {'QUERY PLAN': ' Buffers: shared hit=27280'},
 {'QUERY PLAN': ' -> Nested Loop Left Join (cost=0.42..2156.64 rows=175 width=4) (actual time=16.755..53215.383 rows=33709 loops=1)'},
 {'QUERY PLAN': ' Output: product_template.id'},
 {'QUERY PLAN': ' Inner Unique: true'},
 {'QUERY PLAN': ' Join Filter: (product_template.id = ir_translation.res_id)'},
 {'QUERY PLAN': ' Rows Removed by Join Filter: 576388512'},
 {'QUERY PLAN': ' Buffers: shared hit=27280'},
 {'QUERY PLAN': ' -> Seq Scan on public.product_template (cost=0.00..2145.57 rows=175 width=4) (actual time=0.016..30.750 rows=33709 loops=1)'},
 {'QUERY PLAN': ' Output: product_template.id, product_template.create_uid, product_template.create_date, product_template.write_date, product_template.write_uid, product_template.supply_method, product_template.uos_id, product_template.list_price, product_template.weight, product_template.mes_type, product_template.uom_id, product_template.description_purchase, product_template.uos_coeff, product_template.purchase_ok, product_template.company_id, product_template.name, product_template.state, product_template.loc_rack, product_template.uom_po_id, product_template.type, product_template.description, product_template.loc_row, product_template.description_sale, product_template.procure_method, product_template.rental, product_template.sale_ok, product_template.sale_delay, product_template.loc_case, product_template.produce_delay, product_template.categ_id, product_template.volume, product_template.active, product_template.color, product_template.track_incoming, product_template.track_outgoing, product_template.track_all, product_template.track_production, product_template.sale_line_warn, product_template.sale_line_warn_msg, product_template.purchase_line_warn, product_template.purchase_line_warn_msg, product_template.sequence, product_template.invoice_policy, product_template.service_type, product_template.description_picking, product_template.tracking, product_template.recurring_invoice, product_template.purchase_method, product_template.purchase_requisition, product_template.default_code, product_template.expense_policy, product_template.location_id, product_template.warehouse_id, product_template.hs_code, product_template.responsible_id, product_template.description_pickingout, product_template.description_pickingin, product_template.subscription_template_id, product_template.service_tracking, product_template.message_main_attachment_id, product_template.service_to_purchase, product_template.l10n_cr_uom_id, product_template.l10n_cr_tariff_heading'},
 {'QUERY PLAN': " Filter: (product_template.active AND ((product_template.type)::text = ANY ('{consu,product}'::text[])))"},
 {'QUERY PLAN': ' Rows Removed by Filter: 1297'},
 {'QUERY PLAN': ' Buffers: shared hit=1708'},
 {'QUERY PLAN': ' -> Materialize (cost=0.42..8.45 rows=1 width=4) (actual time=0.000..0.650 rows=17100 loops=33709)'},
 {'QUERY PLAN': ' Output: ir_translation.res_id'},
 {'QUERY PLAN': ' Buffers: shared hit=25572'},
 {'QUERY PLAN': ' -> Index Scan using ir_translation_unique on public.ir_translation (cost=0.42..8.44 rows=1 width=4) (actual time=0.039..21.429 rows=33293 loops=1)'},
 {'QUERY PLAN': ' Output: ir_translation.res_id'},
 {'QUERY PLAN': " Index Cond: (((ir_translation.type)::text = 'model'::text) AND ((ir_translation.name)::text = 'product.template,name'::text) AND ((ir_translation.lang)::text = 'es_CR'::text))"},
 {'QUERY PLAN': " Filter: (ir_translation.value <> ''::text)"},
 {'QUERY PLAN': ' Buffers: shared hit=25572'},
 {'QUERY PLAN': 'Planning time: 0.615 ms'},
 {'QUERY PLAN': 'Execution time: 53219.965 ms'}]


I have ran a manual "vacuum (VERBOSE, ANALYZE) product_template;" and "vacuum (VERBOSE, ANALYZE) ir_translation;" for production.

See the attachments production_vacuum_product_template.png and production_vacuum_ir_translation.png

After, the query plans result for production was:
    {'QUERY PLAN': 'Aggregate (cost=7063.88..7063.89 rows=1 width=8) (actual time=36.513..36.514 rows=1 loops=1)'},
    {'QUERY PLAN': ' Output: count(product_template.id)'},
    {'QUERY PLAN': ' Buffers: shared hit=3580'},
    {'QUERY PLAN': ' -> Hash Left Join (cost=4745.62..6979.65 rows=33693 width=4) (actual time=18.165..34.420 rows=33709 loops=1)'},
    {'QUERY PLAN': ' Output: product_template.id'},
    {'QUERY PLAN': ' Inner Unique: true'},
    {'QUERY PLAN': ' Hash Cond: (product_template.id = ir_translation.res_id)'},
    {'QUERY PLAN': ' Buffers: shared hit=3580'},
    {'QUERY PLAN': ' -> Seq Scan on public.product_template (cost=0.00..2145.57 rows=33693 width=4) (actual time=0.006..10.797 rows=33709 loops=1)'},
    {'QUERY PLAN': ' Output: product_template.id, product_template.create_uid, product_template.create_date, product_template.write_date, product_template.write_uid, product_template.supply_method, product_template.uos_id, product_template.list_price, product_template.weight, product_template.mes_type, product_template.uom_id, product_template.description_purchase, product_template.uos_coeff, product_template.purchase_ok, product_template.company_id, product_template.name, product_template.state, product_template.loc_rack, product_template.uom_po_id, product_template.type, product_template.description, product_template.loc_row, product_template.description_sale, product_template.procure_method, product_template.rental, product_template.sale_ok, product_template.sale_delay, product_template.loc_case, product_template.produce_delay, product_template.categ_id, product_template.volume, product_template.active, product_template.color, product_template.track_incoming, product_template.track_outgoing, product_template.track_all, product_template.track_production, product_template.sale_line_warn, product_template.sale_line_warn_msg, product_template.purchase_line_warn, product_template.purchase_line_warn_msg, product_template.sequence, product_template.invoice_policy, product_template.service_type, product_template.description_picking, product_template.tracking, product_template.recurring_invoice, product_template.purchase_method, product_template.purchase_requisition, product_template.default_code, product_template.expense_policy, product_template.location_id, product_template.warehouse_id, product_template.hs_code, product_template.responsible_id, product_template.description_pickingout, product_template.description_pickingin, product_template.subscription_template_id, product_template.service_tracking, product_template.message_main_attachment_id, product_template.service_to_purchase, product_template.l10n_cr_uom_id, product_template.l10n_cr_tariff_heading'},
    {'QUERY PLAN': " Filter: (product_template.active AND ((product_template.type)::text = ANY ('{consu,product}'::text[])))"},
    {'QUERY PLAN': ' Rows Removed by Filter: 1297'},
    {'QUERY PLAN': ' Buffers: shared hit=1708'},
    {'QUERY PLAN': ' -> Hash (cost=4447.50..4447.50 rows=23849 width=4) (actual time=18.138..18.138 rows=33293 loops=1)'},
    {'QUERY PLAN': ' Output: ir_translation.res_id'},
    {'QUERY PLAN': ' Buckets: 65536 (originally 32768) Batches: 1 (originally 1) Memory Usage: 1683kB'},
    {'QUERY PLAN': ' Buffers: shared hit=1872'},
    {'QUERY PLAN': ' -> Bitmap Heap Scan on public.ir_translation (cost=1124.50..4447.50 rows=23849 width=4) (actual time=5.120..13.517 rows=33293 loops=1)'},
    {'QUERY PLAN': ' Output: ir_translation.res_id'},
    {'QUERY PLAN': " Recheck Cond: (((ir_translation.name)::text = 'product.template,name'::text) AND ((ir_translation.lang)::text = 'es_CR'::text) AND ((ir_translation.type)::text = 'model'::text))"},
    {'QUERY PLAN': " Filter: (ir_translation.value <> ''::text)"},
    {'QUERY PLAN': ' Heap Blocks: exact=1632'},
    {'QUERY PLAN': ' Buffers: shared hit=1872'},
    {'QUERY PLAN': ' -> Bitmap Index Scan on ir_translation_ltn (cost=0.00..1118.54 rows=23850 width=0) (actual time=4.908..4.908 rows=33293 loops=1)'},
    {'QUERY PLAN': " Index Cond: (((ir_translation.name)::text = 'product.template,name'::text) AND ((ir_translation.lang)::text = 'es_CR'::text) AND ((ir_translation.type)::text = 'model'::text))"},
    {'QUERY PLAN': ' Buffers: shared hit=240'},
    {'QUERY PLAN': 'Planning time: 0.363 ms'},
    {'QUERY PLAN': 'Execution time: 36.666 ms'},
    ]

So, the my problem was fixed with VACUUM in production.
Thank you!


El sáb., 25 abr. 2020 a las 15:40, Michael Lewis (<mlewis@entrata.com>) escribió:
The example is nonsensical so I expect it is too contrived to be useful for analyzing the actual problem.

Additionally, the total query time is under 1ms and most of it is planning time. Use a prepared statement or do something else to reduce planning time like reducing statistics target if that actually makes sense for your use case.

Else, show us something much closer to the real problem.


--
Moisés López Calderón
Mobile: (+521) 477-752-22-30
Twitter: @moylop260
hangout: moylop260@vauxoo.com
http://www.vauxoo.com - Odoo Gold Partner
Twitter: @vauxoo
Attachment

pgsql-performance by date:

Previous
From: Laurenz Albe
Date:
Subject: Re: NUMA settings
Next
From: Michael Lewis
Date:
Subject: Re: The query plan get all columns but I'm using only one column.