Strange behavior after upgrade from 9.0 to 9.2

From: Andrzej Zawadzki <zawadaa(at)wp(dot)pl>
To: pgsql-performance(at)postgresql(dot)org
Subject: Strange behavior after upgrade from 9.0 to 9.2
Date: 2012-10-08 08:18:06
Message-ID: 50728C3E.9050904@wp.pl
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

Hi!

After upgrade (dump/restore/analyze) query (below) after some time is killed by kernel.
Postgres creates a lot of tmp files:

temporary file: path "base/pgsql_tmp/pgsql_tmp8949.2046", size 24576
temporary file: path "base/pgsql_tmp/pgsql_tmp8949.2045", size 24576
temporary file: path "base/pgsql_tmp/pgsql_tmp8949.2044", size 32768
temporary file: path "base/pgsql_tmp/pgsql_tmp8949.2043", size 32768
temporary file: path "base/pgsql_tmp/pgsql_tmp8949.2042", size 24576

I have no idea whats wrong. Looks like planer bad decision.

SELECT vwc.* , c.jednzawid as bureau_id ,
c.nazwa as borrower_name ,
c.nrumowy as agreement_number ,
c.kwotakred as credit_amount_gross ,
c.nrumchar as id_ge ,
c.zazndoanuldata as marked_to_cancel_date ,
c.bureau_category_id ,
l.typid as product_type_id ,
cs.doc_receive_tmstp ,
cs.doc_send_path_id ,
cs.first_scan_complete_tmstp ,
cs.verification_doc_not_complete_id ,
cs.verification_phone_not_complete_id ,
caged.requested_doc_send_path_id ,
end_of_validity(c.*,l.*) AS end_of_validity ,
bc.creationdate as last_contact_tmstp ,
last_va.action_status_id as verification_status_id ,
c.verification_assistant_id ,
caged.client_verification_path_id
FROM verification_waiting_credit vwc,
kredyty c LEFT JOIN kredaged caged ON (caged.kredytid = c.id) LEFT
JOIN bureau_contact bc ON (bc.credit_id = c.id AND NOT EXISTS
( SELECT 1 FROM bureau_contact bc1
WHERE bc1.credit_id = bc.credit_id and bc1.id > bc.id)
) LEFT JOIN verification_action last_va ON (last_va.credit_id = c.id
AND NOT EXISTS
(SELECT 1 FROM verification_action va_t
WHERE va_t.id > last_va.id
AND va_t.credit_id = last_va.credit_id)
) , kredytstatus cs , linie l
WHERE true
AND vwc.user_id = 12949
AND vwc.credit_id = c.id
AND vwc.credit_id = cs.kredytid
AND c.linia = l.id
ORDER BY vwc.id

Query plan below (9.2).

"Nested Loop (cost=73132.54..5320352.90 rows=1 width=4681)"
" -> Nested Loop (cost=73132.54..5320345.72 rows=1 width=4416)"
" -> Nested Loop (cost=73132.54..5320334.36 rows=1 width=4392)"
" Join Filter: (vwc.credit_id = c.id)"
" -> Index Scan using verification_waiting_credit_pkey on verification_waiting_credit vwc (cost=0.00..12.97 rows=1 width=156)"
" Filter: (user_id = 12949)"
" -> Hash Left Join (cost=73132.54..5279312.99 rows=3280672 width=4236)"
" Hash Cond: (c.id = bc.credit_id)"
" -> Hash Left Join (cost=73019.54..5119260.82 rows=3280672 width=4228)"
" Hash Cond: (c.id = last_va.credit_id)"
" -> Hash Left Join (cost=24351.16..4650135.04 rows=3280672 width=4224)"
" Hash Cond: (c.id = caged.kredytid)"
" -> Seq Scan on kredyty c (cost=0.00..1202754.72 rows=3280672 width=4216)"
" -> Hash (cost=16741.96..16741.96 rows=437696 width=12)"
" -> Seq Scan on kredaged caged (cost=0.00..16741.96 rows=437696 width=12)"
" -> Hash (cost=45953.74..45953.74 rows=217172 width=8)"
" -> Hash Anti Join (cost=19583.56..45953.74 rows=217172 width=8)"
" Hash Cond: (last_va.credit_id = va_t.credit_id)"
" Join Filter: (va_t.id > last_va.id)"
" -> Seq Scan on verification_action last_va (cost=0.00..15511.58 rows=325758 width=12)"
" -> Hash (cost=15511.58..15511.58 rows=325758 width=8)"
" -> Seq Scan on verification_action va_t (cost=0.00..15511.58 rows=325758 width=8)"
" -> Hash (cost=104.99..104.99 rows=641 width=12)"
" -> Hash Anti Join (cost=49.65..104.99 rows=641 width=12)"
" Hash Cond: (bc.credit_id = bc1.credit_id)"
" Join Filter: (bc1.id > bc.id)"
" -> Seq Scan on bureau_contact bc (cost=0.00..37.62 rows=962 width=16)"
" -> Hash (cost=37.62..37.62 rows=962 width=8)"
" -> Seq Scan on bureau_contact bc1 (cost=0.00..37.62 rows=962 width=8)"
" -> Index Scan using kredytstatus_pkey on kredytstatus cs (cost=0.00..11.35 rows=1 width=32)"
" Index Cond: (kredytid = c.id)"
" -> Index Scan using linie_pkey on linie l (cost=0.00..6.92 rows=1 width=273)"
" Index Cond: (id = c.linia)"

To compare query plan on postgresql 9.0

"Nested Loop (cost=0.00..28892.99 rows=1 width=357)"
" -> Nested Loop Left Join (cost=0.00..28884.11 rows=1 width=333)"
" Join Filter: (bc.credit_id = c.id)"
" -> Nested Loop (cost=0.00..135.81 rows=1 width=325)"
" -> Nested Loop Left Join (cost=0.00..133.03 rows=1 width=293)"
" -> Nested Loop Left Join (cost=0.00..96.01 rows=1 width=289)"
" -> Nested Loop (cost=0.00..92.56 rows=1 width=281)"
" -> Index Scan using verification_waiting_credit_pkey on verification_waiting_credit vwc (cost=0.00..83.92 rows=1 width=156)"
" Filter: (user_id = 12949)"
" -> Index Scan using kredyty_desc_pkey on kredyty c (cost=0.00..8.63 rows=1 width=125)"
" Index Cond: (c.id = vwc.credit_id)"
" -> Index Scan using kredaged_pkey on kredaged caged (cost=0.00..3.44 rows=1 width=12)"
" Index Cond: (caged.kredytid = c.id)"
" -> Index Scan using verification_action_credit_id_idx on verification_action last_va (cost=0.00..37.00 rows=2 width=8)"
" Index Cond: (last_va.credit_id = c.id)"
" Filter: (NOT (SubPlan 2))"
" SubPlan 2"
" -> Index Scan using verification_action_credit_id_idx on verification_action va_t (cost=0.00..8.38 rows=1 width=0)"
" Index Cond: (credit_id = $3)"
" Filter: (id > $2)"
" -> Index Scan using linie_pkey on linie l (cost=0.00..2.77 rows=1 width=40)"
" Index Cond: (l.id = c.linia)"
" -> Seq Scan on bureau_contact bc (cost=0.00..28742.08 rows=498 width=12)"
" Filter: (NOT (SubPlan 1))"
" SubPlan 1"
" -> Index Scan using bureau_contact_pkey on bureau_contact bc1 (cost=0.00..28.79 rows=1 width=0)"
" Index Cond: (id > $1)"
" Filter: (credit_id = $0)"
" -> Index Scan using kredytstatus_pkey on kredytstatus cs (cost=0.00..8.62 rows=1 width=32)"
" Index Cond: (cs.kredytid = vwc.credit_id)"

Query run time 52ms

Best regards

--
Andrzej Zawadzki

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Craig Ringer 2012-10-08 10:15:15 Re: Strange behavior after upgrade from 9.0 to 9.2
Previous Message Undertaker Rude 2012-10-08 07:39:26 Re: Same query doing slow then quick