Re: Log full with gigabyes of CurTransactionContex

From: Suresh Borse <s(dot)borse(at)direction(dot)biz>
To: Iñigo Martinez Lasala <imartinez(at)vectorsf(dot)com>
Cc: pgsql-admin(at)postgresql(dot)org
Subject: Re: Log full with gigabyes of CurTransactionContex
Date: 2009-06-15 10:10:53
Message-ID: 1245060653.2239.17.camel@dss-052.dsslp.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-admin

Please ignore my previous comment..

Try by increasing the shared_buffer size

On Mon, 2009-06-15 at 11:54 +0200, Iñigo Martinez Lasala wrote:

> Hi Everybody.
>
> We have a problem with an insert query in one of our clients. This
> query is launched in a night batch process. We have observed that if
> change set is big (more than 50.000 updates) our database log starts
> growing with thousands and thousands of lines until the server is out
> of space and database freezes.
>
> This is the query.
>
> set statement_timeout=0;
> delete from fnac.alta_stock_precio;
> insert into fnac.alta_stock_precio
> select
> asp_id_fnac,asp_stock,asp_stock_local,asp_pmp,asp_pe,asp_pmv,asp_ventas,asp_id_ean,asp_stock_local_2,asp_stock_almacen_central
> from fnac.articulo a , fnac.v_alta_s_p va
> where ((asp_id_fnac)::text = (asp_id_fnac)::text) and
> (art_descatalogado = 0 or (art_descatalogado=1 and
> nvl(va.asp_stock_local_2,0)>0) ) and
> lpad(a.art_id_ean,13,0) = lpad(va.asp_id_ean,13,0) and
> (nvl(a.art_stock,0) <> nvl(va.asp_stock,0) or
> nvl(a.art_stock_local,0) <> nvl(va.asp_stock_local,0) or
> nvl(a.art_stock_local_2,0) <> nvl(va.asp_stock_local_2,0) or
> nvl(a.art_stock_almacen_central,0) <>
> nvl(va.asp_stock_almacen_central,0) or nvl(a.art_pmv,0) <>
> nvl(va.asp_pmv,0) or nvl(a.art_precio_fnac_web,0) <>
> nvl(va.asp_pmv,0) or nvl(a.art_pe,0) <> nvl(va.asp_pe,0) or
> nvl(a.art_pmp,0) <> nvl(va.asp_pmp,0) );
>
>
> nvl is a simple function (coalesce). This application was translated
> from Oracle, so instead of replace nvl with colaesce, developers
> created a function called nvl that is a wrapper to coalesce.
>
> Our database server runs under RedHat ES 5.3, with PAE enabled, 16GB
> and postgres 8.2.13 32bit.
>
> Postgresql main parameters:
> shared_buffers = 2000MB
> temp_buffers = 100MB
> max_prepared_transactions =10
> work_mem = 2000MB
> maintenance_work_mem = 1024M
> effective_cache_size = 13GB
>
> Well. If count from select is higher that 50.000, log gets writing
> this:
>
> TopMemoryContext: 9764864 total in 1191 blocks; 27968 free (1195
> chunks); 9736896 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 1024 total in 1 blocks; 256 free (0 chunks); 768 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 7168 total in 3 blocks; 3288 free (0 chunks); 3880 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 3072 total in 2 blocks; 1360 free (0 chunks); 1712 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 7168 total in 3 blocks; 3248 free (0 chunks); 3920 used
> --More--
> SPI Plan: 7168 total in 3 blocks; 2568 free (0 chunks); 4600 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 3072 total in 2 blocks; 1408 free (1 chunks); 1664 used
> SPI Plan: 7168 total in 3 blocks; 3704 free (0 chunks); 3464 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 1024 total in 1 blocks; 256 free (0 chunks); 768 used
> SPI Plan: 1024 total in 1 blocks; 256 free (0 chunks); 768 used
> SPI Plan: 3072 total in 2 blocks; 1296 free (0 chunks); 1776 used
> SPI Plan: 3072 total in 2 blocks; 2000 free (0 chunks); 1072 used
> SPI Plan: 3072 total in 2 blocks; 672 free (0 chunks); 2400 used
> SPI Plan: 3072 total in 2 blocks; 1328 free (0 chunks); 1744 used
> SPI Plan: 7168 total in 3 blocks; 3896 free (0 chunks); 3272 used
> SPI Plan: 7168 total in 3 blocks; 3896 free (0 chunks); 3272 used
> SPI Plan: 3072 total in 2 blocks; 56 free (0 chunks); 3016 used
> SPI Plan: 3072 total in 2 blocks; 1872 free (0 chunks); 1200 used
> SPI Plan: 3072 total in 2 blocks; 1872 free (0 chunks); 1200 used
> SPI Plan: 3072 total in 2 blocks; 1872 free (0 chunks); 1200 used
> SPI Plan: 1024 total in 1 blocks; 0 free (0 chunks); 1024 used
> SPI Plan: 1024 total in 1 blocks; 0 free (0 chunks); 1024 used
> SPI Plan: 1024 total in 1 blocks; 0 free (0 chunks); 1024 used
> PL/PgSQL function context: 24576 total in 2 blocks; 10592 free (6
> chunks); 13984 used
> SPI Plan: 31744 total in 6 blocks; 5392 free (0 chunks); 26352 used
> SPI Plan: 3072 total in 2 blocks; 1840 free (0 chunks); 1232 used
> SPI Plan: 3072 total in 2 blocks; 1840 free (0 chunks); 1232 used
> SPI Plan: 3072 total in 2 blocks; 1408 free (1 chunks); 1664 used
> SPI Plan: 3072 total in 2 blocks; 1840 free (0 chunks); 1232 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 3072 total in 2 blocks; 1408 free (1 chunks); 1664 used
> SPI Plan: 7168 total in 3 blocks; 3248 free (0 chunks); 3920 used
> SPI Plan: 7168 total in 3 blocks; 2568 free (0 chunks); 4600 used
> SPI Plan: 3072 total in 2 blocks; 1136 free (0 chunks); 1936 used
> SPI Plan: 1024 total in 1 blocks; 64 free (0 chunks); 960 used
> PL/PgSQL function context: 8192 total in 1 blocks; 7712 free (4
> chunks); 480 used
> SPI Plan: 3072 total in 2 blocks; 1360 free (0 chunks); 1712 used
> SPI Plan: 1024 total in 1 blocks; 240 free (0 chunks); 784 used
> SPI Plan: 1024 total in 1 blocks; 256 free (0 chunks); 768 used
> --More--
> SPI Plan: 3072 total in 2 blocks; 1408 free (1 chunks); 1664 used
> SPI Plan: 3072 total in 2 blocks; 1840 free (0 chunks); 1232 used
> SPI Plan: 1024 total in 1 blocks; 192 free (0 chunks); 832 used
> SPI Plan: 1024 total in 1 blocks; 256 free (0 chunks); 768 used
> SPI Plan: 1024 total in 1 blocks; 192 free (0 chunks); 832 used
> SPI Plan: 1024 total in 1 blocks; 256 free (0 chunks); 768 used
> SPI Plan: 3072 total in 2 blocks; 1120 free (0 chunks); 1952 used
> SPI Plan: 1024 total in 1 blocks; 256 free (0 chunks); 768 used
> SPI Plan: 1024 total in 1 blocks; 192 free (0 chunks); 832 used
> SPI Plan: 1024 total in 1 blocks; 256 free (0 chunks); 768 used
> SPI Plan: 1024 total in 1 blocks; 192 free (0 chunks); 832 used
> SPI Plan: 1024 total in 1 blocks; 256 free (0 chunks); 768 used
> SPI Plan: 1024 total in 1 blocks; 192 free (0 chunks); 832 used
> SPI Plan: 1024 total in 1 blocks; 256 free (0 chunks); 768 used
> SPI Plan: 1024 total in 1 blocks; 192 free (0 chunks); 832 used
> SPI Plan: 1024 total in 1 blocks; 256 free (0 chunks); 768 used
> SPI Plan: 1024 total in 1 blocks; 192 free (0 chunks); 832 used
> SPI Plan: 15360 total in 4 blocks; 912 free (0 chunks); 14448 used
> PL/PgSQL function context: 57344 total in 3 blocks; 30376 free (23
> chunks); 26968 used
> SPI Plan: 1024 total in 1 blocks; 32 free (0 chunks); 992 used
> PL/PgSQL function context: 8192 total in 1 blocks; 7256 free (3
> chunks); 936 used
> CFuncHash: 8192 total in 1 blocks; 4936 free (0 chunks); 3256 used
> Rendezvous variable hash: 8192 total in 1 blocks; 3848 free (0
> chunks); 4344 used
> PLpgSQL function cache: 24328 total in 2 blocks; 5904 free (0 chunks);
> 18424 used
> Type information cache: 8192 total in 1 blocks; 1800 free (0 chunks);
> 6392 used
> TopTransactionContext: 2088960 total in 8 blocks; 873576 free (0
> chunks); 1215384 used
> SPI Exec: 8192 total in 1 blocks; 7992 free (0 chunks); 200 used
> ExecutorState: 8192 total in 1 blocks; 3080 free (0 chunks); 5112 used
> ExprContext: 0 total in 0 blocks; 0 free (0 chunks); 0 used
> SPI Proc: 8192 total in 1 blocks; 7848 free (11 chunks); 344 used
> CurTransactionContext: 0 total in 0 blocks; 0 free (0 chunks); 0 used
> AfterTriggerEvents: 8192 total in 1 blocks; 8136 free (0 chunks); 56
> used
> ExecutorState: 122880 total in 4 blocks; 40264 free (9 chunks); 82616
> used
> ExprContext: 8192 total in 1 blocks; 8176 free (0 chunks); 16 used
> SPI Exec: 8192 total in 1 blocks; 7760 free (0 chunks); 432 used
> AfterTriggerTupleContext: 0 total in 0 blocks; 0 free (0 chunks); 0
> used
> ExecutorState: 159908 total in 8 blocks; 56920 free (8 chunks); 102988
> used
> ExprContext: 8192 total in 1 blocks; 8176 free (0 chunks); 16 used
> TIDBitmap: 8192 total in 1 blocks; 3912 free (0 chunks); 4280 used
> ExprContext: 8192 total in 1 blocks; 8136 free (0 chunks); 56 used
> ExprContext: 0 total in 0 blocks; 0 free (0 chunks); 0 used
> ExprContext: 8192 total in 1 blocks; 8176 free (0 chunks); 16 used
> SPI Proc: 8192 total in 1 blocks; 4960 free (1 chunks); 3232 used
> CurTransactionContext: 8192 total in 1 blocks; 8176 free (5 chunks);
> 16 used
> CurTransactionContext: 8192 total in 1 blocks; 8176 free (5 chunks);
> 16 used
> CurTransactionContext: 8192 total in 1 blocks; 8176 free (5 chunks);
> 16 used
> CurTransactionContext: 8192 total in 1 blocks; 8176 free (5 chunks);
> 16 used
> CurTransactionContext: 8192 total in 1 blocks; 8176 free (5 chunks);
> 16 used
> CurTransactionContext: 8192 total in 1 blocks; 8176 free (5 chunks);
> 16 used
> CurTransactionContext: 8192 total in 1 blocks; 8176 free (5 chunks);
> 16 used
> CurTransactionContext: 8192 total in 1 blocks; 8176 free (5 chunks);
> 16 used
> CurTransactionContext: 8192 total in 1 blocks; 8176 free (5 chunks);
> 16 used
> CurTransactionContext: 8192 total in 1 blocks; 8176 free (5 chunks);
> 16 used
> CurTransactionContext: 8192 total in 1 blocks; 8176 free (5 chunks);
> 16 used
> CurTransactionContext: 8192 total in 1 blocks; 8176 free (5 chunks);
> 16 used
> CurTransactionContext: 8192 total in 1 blocks; 8176 free (5 chunks);
> 16 used
> CurTransactionContext: 8192 total in 1 blocks; 8176 free (5 chunks);
> 16 used
> FOREVER UNTIL OUT OF SPACE....
>
> Any hints?
> Increasing temp buffers could help?
>
> Thanks in advance.

Thanks & Regards,

Suresh Borse
(DBA)
_________________________________________________________________________________________
DIRECTION SOFTWARE SOLUTIONS
5, Brady Gladys Plaza, 1/447, Senapati Bapat Marg, Lower Parel, Mumbai -
400 013
Tel. : 91 22 66615000 (Ext: 350) Fax : 91 22
24911046
Cell : 91 9422 239338 Site :
www.direction.biz
_________________________________________________________________________________________

In response to

Browse pgsql-admin by date

  From Date Subject
Next Message Tom Lane 2009-06-15 14:02:26 Re: Log full with gigabyes of CurTransactionContex
Previous Message Suresh Borse 2009-06-15 10:07:32 Re: Log full with gigabyes of CurTransactionContex