Re: Auditing extension for PostgreSQL (Take 2)

On Wed, Apr 15, 2015 at 10:52 AM, Sawada Masahiko <sawada.mshk@gmail.com> wrote:
> On Wed, Apr 15, 2015 at 8:57 AM, David Steele <david@pgmasters.net> wrote:
>> On 4/14/15 7:13 PM, Tatsuo Ishii wrote:
>>> This patch does not apply cleanly due to the moving of pgbench (patch
>>> to filelist.sgml failed).
>>
>> Thank you for pointing that out!
>>
>> Ironic that it was the commit directly after the one I was testing with
>> that broke the patch.  It appears the end of the last CF is a very bad
>> time to be behind HEAD.
>>
>> Fixed in attached v8 patch.
>
> Thank you for updating the patch!
>
> I applied the patch and complied them successfully without WARNING.
>
> I tested v8 patch with CURSOR case I mentioned before, and got
> segmentation fault again.
> Here are log messages in my environment,
>
> =# select test();
>  LOG:  server process (PID 29730) was terminated by signal 11:
> Segmentation fault
> DETAIL:  Failed process was running: select test();
> LOG:  terminating any other active server processes
> WARNING:  terminating connection because of crash of another server process
> DETAIL:  The postmaster has commanded this server process to roll back
> the current transaction and exit, because another server process
> exited abnormally and possibly corrupted shared memory.
> HINT:  In a moment you should be able to reconnect to the database and
> repeat your command.
> FATAL:  the database system is in recovery mode
>
> I hope that these messages helps you to address this problem.
> I will also try to address this.
>
> Regards,
>
> -------
> Sawada Masahiko



> I will also try to address this.

I investigated this problem and inform you my result here.

When we execute test() function I mentioned, the three stack items in
total are stored into auditEventStack.
The two of them are freed by stack_pop() -> stack_free() (i.g,
stack_free() is called by stack_pop()).
One of them is freed by PortalDrop() -> .. ->
MemoryContextDeleteChildren() -> ... -> stack_free().
And it is freed at the same time as deleting pg_audit memory context,
and stack will be completely empty.

But after freeing all items, finish_xact_command() function could call
PortalDrop(), so ExecutorEnd() function could be called again.
pg_audit has ExecutorEnd_hook, so postgres tries to free that item.. SEGV.

In my environment, the following change fixes it.

--- pg_audit.c.org    2015-04-15 14:21:07.541866525 +0900
+++ pg_audit.c    2015-04-15 11:36:53.758877339 +0900
@@ -1291,7 +1291,7 @@        standard_ExecutorEnd(queryDesc);
    /* Pop the audit event off the stack */
-    if (!internalStatement)
+    if (!internalStatement && auditEventStack != NULL)    {        stack_pop(auditEventStack->stackId);    }

It might be good idea to add Assert() at before calling stack_pop().

I'm not sure this change is exactly correct, but I hope this
information helps you.

Regards,

-------
Sawada Masahiko