On 5/20/2010 12:18 PM, Jeff wrote:
> On May 20, 2010, at 11:33 AM, Jeff wrote:
> 
>> it happened again - wanted to get this post out before I do more  
>> digging:
>>
>> table summary as an on delete cascade FK into sourcereports.
>> we delete from sourcereports.
>> the RI trigger deletes from summary (5700) but does not fire the log  
>> trigger yet.
>> we go on our merry way nuking events.
>> then my summary update trigger runs - the delete inside it does  
>> nothing due to the FK already nuking the row then proceeds to insert  
>> into it.
>> then we execute the slon logger for the original FK delete and it  
>> records a delete record after the insert.
>>
>> then someone comes along and loads a new report for the same  
>> sourceid (to avoid confusion, it is a company identifier)
>>
>> I need to flesh this out a bit more but I think it is related, I'll  
>> report back in a bit with more details.
>>
>>
> 
> I have a test case here - turns out the bug is ultimately in my code  
> and there is really nothing slony can do about it. but I figure for  
> the good of the world, I'll present my findings.
> 
> we have a table testsource and another table testsummary which has an  
> on delete fk to testsource(id).
> I added a number of triggers onto them to simulate slony and my own  
> code:
> 
> indie=> insert into testsource(company) values (2);
> NOTICE:  logger - OP: INSERT REL: testsource WHEN: AFTER
> NOTICE:  update summary
> NOTICE:  tabaction - OP: INSERT REL: testsummary WHEN: BEFORE
> CONTEXT:  SQL statement "insert into testsummary (company, source_id)  
> values ( $1 ,  $2 )"
> PL/pgSQL function "testupdatesummary" line 18 at SQL statement
> NOTICE:  logger - OP: INSERT REL: testsummary WHEN: AFTER
> CONTEXT:  SQL statement "insert into testsummary (company, source_id)  
> values ( $1 ,  $2 )"
> PL/pgSQL function "testupdatesummary" line 18 at SQL statement
> NOTICE:  tabaction - OP: INSERT REL: testsummary WHEN: AFTER
> CONTEXT:  SQL statement "insert into testsummary (company, source_id)  
> values ( $1 ,  $2 )"
> PL/pgSQL function "testupdatesummary" line 18 at SQL statement
> INSERT 0 1
> indie=> select * from testsource;
>   id | company | data
> ----+---------+------
>    2 |       2 |
> (1 row)
> 
> things look sane.
> now lets nuke it:
> 
> indie=> delete from testsource where id = 2;
> NOTICE:  tabaction - OP: DELETE REL: testsummary WHEN: BEFORE
> CONTEXT:  SQL statement "DELETE FROM ONLY "public"."testsummary" WHERE  
> $1 OPERATOR(pg_catalog.=) "source_id""
> NOTICE:  logger - OP: DELETE REL: testsource WHEN: AFTER
> NOTICE:  update summary
> NOTICE:  tabaction - OP: INSERT REL: testsummary WHEN: BEFORE
> CONTEXT:  SQL statement "insert into testsummary (company, source_id)  
> values ( $1 ,  $2 )"
> PL/pgSQL function "testupdatesummary" line 18 at SQL statement
> NOTICE:  logger - OP: INSERT REL: testsummary WHEN: AFTER
> CONTEXT:  SQL statement "insert into testsummary (company, source_id)  
> values ( $1 ,  $2 )"
> PL/pgSQL function "testupdatesummary" line 18 at SQL statement
> NOTICE:  tabaction - OP: INSERT REL: testsummary WHEN: AFTER
> CONTEXT:  SQL statement "insert into testsummary (company, source_id)  
> values ( $1 ,  $2 )"
> PL/pgSQL function "testupdatesummary" line 18 at SQL statement
> NOTICE:  logger - OP: DELETE REL: testsummary WHEN: AFTER
> NOTICE:  tabaction - OP: DELETE REL: testsummary WHEN: AFTER
> DELETE 1
>
> first we see a before trigger for the FK fire.
> then we log our delete from testsource, which fires the summary update  
> trigger
> since the summary for that company is gone we do not delete and just  
> insert and log that.
> after that the after trigger from the fk delete is fired, which logs.
> 
> so the main bug is the FK in testsummary is wrong and not needed. the  
> other is the ordering of operations from there, but I don't think  
> slony can do anything about it.  it is a bit interesting the FK stuff  
> occurs in an odd sequence though. I would have expected the after  
> triggers to fire after the fk induced delete...

I rather think that the problem is that your trigger updating the 
summary is a BEFORE trigger. If you turn that into an AFTER trigger that 
is named so that it fires after the FK CASCADE did its job, the problem 
may go away.

This is an interesting test case.


Jan

-- 
Anyone who trades liberty for security deserves neither
liberty nor security. -- Benjamin Franklin