Re: Configuration of pgaudit settings in postgreSQL.conf causes postgreSQL to fail to start

Jeff/Arthur,

Thanks. I am testing on version 9.5.7 with pgaudit 1.0.6. The production system is currently 9.5.7 but will receive updates to 9.5.9 and beyond as updates are made available. I will paste in here info from the postgreSQL logs and then a couple entries from Event Viewer. Sadly, those event viewer entries show little.

PostgreSQL logs showing startup, after which I ran SET command (SET pgaudit.log = 'READ, WRITE, DDL, ROLE';) and tested with a couple role changes (note that those entries in the log show pgaudit functioning). I then uncommented the pgaudit.log setting in postgresql.conf and restarted the service. Logs show the shutdown.

2017-09-14 14:59:11.148 UTC 59ba993f.3f0 2017-09-14 14:59:11 UTC 00000 1008 :LOG: database system was shut down at 2017-09-14 14:56:28 UTC

2017-09-14 14:59:11.192 UTC 59ba993f.3f0 2017-09-14 14:59:11 UTC 00000 1008 :LOG: MultiXact member wraparound protections are now enabled

2017-09-14 14:59:11.199 UTC 59ba993e.a64 2017-09-14 14:59:10 UTC 00000 2660 :LOG: database system is ready to accept connections

2017-09-14 14:59:11.376 UTC 59ba993e.a64 2017-09-14 14:59:10 UTC 00000 2660 :LOG: setsockopt(TCP_KEEPCNT) not supported

2017-09-14 14:59:11.857 UTC 59ba993f.da4 2017-09-14 14:59:11 UTC 00000 3492 :LOG: autovacuum launcher started

2017-09-14 14:59:12.218 UTC [unknown] 59ba9940.f1c 2017-09-14 14:59:12 UTC [unknown] 00000 3868 ::1(49306) [unknown]:LOG: connection received: host=::1 port=49306

2017-09-14 15:00:23.335 UTC 59ba993e.a64 2017-09-14 14:59:10 UTC 00000 2660 :LOG: setsockopt(TCP_KEEPCNT) not supported

2017-09-14 15:00:23.498 UTC [unknown] 59ba9987.b2c 2017-09-14 15:00:23 UTC [unknown] 00000 2860 ::1(49307) [unknown]:LOG: connection received: host=::1 port=49307

2017-09-14 15:00:32.668 UTC 59ba993e.a64 2017-09-14 14:59:10 UTC 00000 2660 :LOG: setsockopt(TCP_KEEPCNT) not supported

2017-09-14 15:00:32.827 UTC [unknown] 59ba9990.8b0 2017-09-14 15:00:32 UTC [unknown] 00000 2224 ::1(49308) [unknown]:LOG: connection received: host=::1 port=49308

2017-09-14 15:00:32.850 UTC postgres 59ba9990.8b0 2017-09-14 15:00:32 UTC postgres 00000 2224 ::1(49308) [unknown]:LOG: connection authorized: user=postgres database=postgres

2017-09-14 15:05:37.975 UTC postgres 59ba9990.8b0 2017-09-14 15:00:32 UTC postgres 00000 2224 ::1(49308) psql:LOG: AUDIT: SESSION,1,1,ROLE,CREATE ROLE,,,CREATE ROLE test;,<not logged>

2017-09-14 15:07:31.922 UTC postgres 59ba9990.8b0 2017-09-14 15:00:32 UTC postgres 00000 2224 ::1(49308) psql:LOG: AUDIT: SESSION,2,1,ROLE,DROP ROLE,,,DROP ROLE test;,<not logged>

2017-09-14 15:08:16.821 UTC 59ba993e.a64 2017-09-14 14:59:10 UTC 00000 2660 :LOG: received fast shutdown request

2017-09-14 15:08:16.822 UTC 59ba993e.a64 2017-09-14 14:59:10 UTC 00000 2660 :LOG: aborting any active transactions

2017-09-14 15:08:16.827 UTC postgres 59ba9990.8b0 2017-09-14 15:00:32 UTC postgres 57P01 2224 ::1(49308) psql:FATAL: terminating connection due to administrator command

2017-09-14 15:08:16.828 UTC postgres 59ba9990.8b0 2017-09-14 15:00:32 UTC postgres 00000 2224 ::1(49308) psql:LOG: disconnection: session time: 0:07:44.000 user=postgres database=postgres host=::1 port=49308

2017-09-14 15:08:16.829 UTC 59ba993f.da4 2017-09-14 14:59:11 UTC 00000 3492 :LOG: autovacuum launcher shutting down

2017-09-14 15:08:16.833 UTC 59ba993f.bec 2017-09-14 14:59:11 UTC 00000 3052 :LOG: shutting down

2017-09-14 15:08:17.141 UTC 59ba993f.bec 2017-09-14 14:59:11 UTC 00000 3052 :LOG: database system is shut down

The following entries from event viewer show the service attempting to restart and ultimately failing. No further logs/entries occur in the pg_log.:

- <Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
- <System>
<Provider Name="PostgreSQL" />
<EventID Qualifiers="0">0</EventID>
<Level>4</Level>
<Task>0</Task>
<Keywords>0x80000000000000</Keywords>
<TimeCreated SystemTime="2017-09-14T15:08:52.000000000Z" />
<EventRecordID>10900</EventRecordID>
<Channel>Application</Channel>
<Computer>JWIN2012-11_1_2</Computer>
<Security />
</System>
- <EventData>
<Data>Waiting for server startup...</Data>
</EventData>
</Event>

- <Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
- <System>
<Provider Name="PostgreSQL" />
<EventID Qualifiers="0">0</EventID>
<Level>2</Level>
<Task>0</Task>
<Keywords>0x80000000000000</Keywords>
<TimeCreated SystemTime="2017-09-14T15:08:53.000000000Z" />
<EventRecordID>10901</EventRecordID>
<Channel>Application</Channel>
<Computer>JWIN2012-11_1_2</Computer>
<Security />
</System>
- <EventData>
<Data>Timed out waiting for server startup</Data>
</EventData>
</Event>

v/r

Troy R. Hardin

________________________________
From: Jeff Janes <jeff(dot)janes(at)gmail(dot)com>
Sent: Thursday, September 14, 2017 10:33:02 AM
To: Artur Zakirov
Cc: pgsql-general(at)postgresql(dot)org; Troy Hardin
Subject: Re: [GENERAL] Configuration of pgaudit settings in postgreSQL.conf causes postgreSQL to fail to start

On Sep 14, 2017 7:07 AM, "Arthur Zakirov" <a(dot)zakirov(at)postgrespro(dot)ru<mailto:a(dot)zakirov(at)postgrespro(dot)ru>> wrote:
On Wed, Sep 13, 2017 at 02:42:18PM +0000, Troy Hardin wrote:
> Putting either of these two lines in the .conf file cause it to fail to start.

Can you show error messages from logs?

And the version.