Re: The query plan get all columns but I'm using only one column.

From: Moises Lopez <moylop260(at)vauxoo(dot)com>
To: Michael Lewis <mlewis(at)entrata(dot)com>
Cc: Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us>, Pgsql Performance <pgsql-performance(at)lists(dot)postgresql(dot)org>
Subject: Re: The query plan get all columns but I'm using only one column.
Date: 2020-04-29 19:21:37
Message-ID: CAGro9RXPZP-NC7wpYzuWgEM8bm7o276wG7DEQt7nZtpDuk-GOw@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

Hello,
Thanks for reply

I have 2 environments production and staging.

The pg_settings result for both environment is the same:
name setting min_val max_val context
effective_cache_size 3,145,728 1 2,147,483,647 user
shared_buffers 1,048,576 16 1,073,741,823 postmaster
work_mem 5,592 64 2,147,483,647 user
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(at)entrata(dot)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(at)vauxoo(dot)com
http://www.vauxoo.com - Odoo Gold Partner
Twitter: @vauxoo

Attachment Content-Type Size
production_vacuum_ir_translation.png image/png 200.8 KB
production_vacuum_product_template.png image/png 172.0 KB

In response to

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Michael Lewis 2020-04-29 19:36:35 Re: The query plan get all columns but I'm using only one column.
Previous Message Laurenz Albe 2020-04-29 08:50:54 Re: NUMA settings