Thread: Logged statement apparently did not commited...

Logged statement apparently did not commited...

From
Ioana Danes
Date:
Hello Everyone,

I would like to kindly ask for your help regarding a strange situation I meet yesterday. It might not be a postgres
issuebut I run out of ideas on what to test or check and so far I could not reproduce the behavior. 

I have 2 (master - slave) postgres 9.0.3 databases running on SLES 11 PATCHLEVEL 1 (x86_64). For the slave I am using a
statementbased replication (terracotta)... 

I have a cron that runs at 1:00am and checks if the dbs are in sync (it exports the data on a text file and makes a
diffon the files generated on the 2 dbs).  

2 days ago I've got differences for a table and I started to investigate the problem.

Postgres log is enabled on both dbs and I could compare the statements. The same statements appear in postgres log on
bothdbs in the same order, no errors or weird stuff. So the dbs should be in sync. 

That table holds temporary information for an item. So there are inserts and updates on that table for an item (key1)
andwhenever that item expires all the data for that item gets deleted: 

insert into mytable (key1, key2, keyval) values (1019, 1, 50);
insert into mytable (key1, key2, keyval) values (1019, 2, 100);
insert into mytable (key1, key2, keyval) values (1019, 3, 10);
update mytable set keyval = 51 where key1 =1019 and key2 = 1;
update mytable set keyval = 102 where key1 =1019 and key2 = 2;
insert into mytable (key1, key2, keyval) values (1019, 4, 10);
...
delete from mytable where key1 = 1019;

Re: Logged statement apparently did not commited...

From
Ioana Danes
Date:
Hi,

I found the issue and of course as you already suspected it was not postgres related.

Thanks a lot for doing such a great job,
Ioana

--- On Fri, 2/18/11, Ioana Danes <ioanasoftware@yahoo.ca> wrote:

> From: Ioana Danes <ioanasoftware@yahoo.ca>
> Subject: [GENERAL] Logged statement apparently did not commited...
> To: pgsql-general@postgresql.org
> Received: Friday, February 18, 2011, 1:43 PM
> Hello Everyone,
>
> I would like to kindly ask for your help regarding a
> strange situation I meet yesterday. It might not be a
> postgres issue but I run out of ideas on what to test or
> check and so far I could not reproduce the behavior.
>
> I have 2 (master - slave) postgres 9.0.3 databases running
> on SLES 11 PATCHLEVEL 1 (x86_64). For the slave I am using a
> statement based replication (terracotta)...
>
> I have a cron that runs at 1:00am and checks if the dbs are
> in sync (it exports the data on a text file and makes a diff
> on the files generated on the 2 dbs).
>
> 2 days ago I've got differences for a table and I started
> to investigate the problem.
>
> Postgres log is enabled on both dbs and I could compare the
> statements. The same statements appear in postgres log on
> both dbs in the same order, no errors or weird stuff. So the
> dbs should be in sync.
>
> That table holds temporary information for an item. So
> there are inserts and updates on that table for an item
> (key1) and whenever that item expires all the data for that
> item gets deleted:
>
> insert into mytable (key1, key2, keyval) values (1019, 1,
> 50);
> insert into mytable (key1, key2, keyval) values (1019, 2,
> 100);
> insert into mytable (key1, key2, keyval) values (1019, 3,
> 10);
> update mytable set keyval = 51 where key1 =1019 and key2 =
> 1;
> update mytable set keyval = 102 where key1 =1019 and key2 =
> 2;
> insert into mytable (key1, key2, keyval) values (1019, 4,
> 10);
> ...
> delete from mytable where key1 = 1019;
>
> From the script that compares the 2 dbs it looks like the
> delete statement for a particular item did not commited on
> the slave. On the master there were no records for the item
> with key1 = 1019 but on db2 there were all the records
> generated by the insert and update statements....(I did
> extracted the insert and update statement from the log and
> it is exactly what the difference is). So it looks pretty
> clear that the delete did not commited on the slave. The
> delete statement appears in postgres log with begin and
> commit transaction and no errors.
>
> The autovacuum is on and it gives a little information on
> what happened between 2 autovacuums:
>
> before autovacuum there are 19 records in the key table for
> key1= 1019
>
> first autovacuum:
> 2011-02-16 13:12:41.088
> CST,,,10691,,4d5c21a9.29c3,1,,2011-02-16 13:12:41
> CST,5/9551,0,LOG,00000,"automatic vacuum of table ""..."":
> index scans: 1
> pages: 0 removed, 1 remain
> tuples: 65 removed, 19 remain
>
> between the autovacuums there are:
>
> 14 inserts for key1 = 1019
> 47 updates for key1 = 1019
>
> 25 inserts for key1 = 1021
> 98 updates for key1 = 1021
>
> 33 records deleted for key1 = 1019
>
> the second autovacuum:
> 2011-02-16 13:52:20.358
> CST,,,10868,,4d5c2af4.2a74,1,,2011-02-16 13:52:20
> CST,5/9795,0,LOG,00000,"automatic vacuum of table ""..."":
> index scans: 1
> pages: 0 removed, 2 remain
> tuples: 98 removed, 58 remain
>
> It looks like autovacuum only removed the dead tuples
> generated by the 98 updates on key 1021 and none of the dead
> tuples generated by the update and delete on item 1019...
>
> Can this be on any help? Does anyone have an idea where
> else to look for clues?
>
> Thank you for your time,
> Ioana
>
>
>
> --
> Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
> To make changes to your subscription:
> http://www.postgresql.org/mailpref/pgsql-general
>