Re: Somewhat odd messages being logged on replicated server

On 9/29/2010 8:55 PM, Jeff Davis wrote:
> On Wed, 2010-09-29 at 20:04 -0500, Karl Denninger wrote:
>> Sep 29 19:58:54 dbms2 postgres[8564]: [2-2] STATEMENT: update post set
>> views = (select views from post where number='116763' and toppost='1') +
>> 1 where number='116763' and toppost='1'
>> Sep 29 20:01:11 dbms2 postgres[8581]: [2-1] ERROR: cannot execute
>> UPDATE in a read-only transaction
>> Sep 29 20:01:11 dbms2 postgres[8581]: [2-2] STATEMENT: update post set
>> views = (select views from post where number='2040327' and toppost='1')
>> + 1 where number='2040327' and toppost='1'
>> Sep 29 20:02:02 dbms2 postgres[8582]: [2-1] ERROR: cannot execute
>> UPDATE in a read-only transaction
>> Sep 29 20:02:02 dbms2 postgres[8582]: [2-2] STATEMENT: update post set
>> views = (select views from post where number='140406' and toppost='1') +
>> 1 where number='140406' and toppost='1'
>> Sep 29 20:04:58 dbms2 postgres[8586]: [2-1] ERROR: cannot execute
>> UPDATE in a read-only transaction
>>
>> When I go look at the value of "views" on both the master and replicated
>> slave, they have the same value..... so I'm not sure why the error is
>> showing up.
>>
>> There are no clients attempting to connect to the replicated server at
>> all at this point (I will enable that later once I'm satisfied that it
>> is working in the general sense), so this has to be coming from the
>> replication system itself.
> It looks very much like clients are connecting and issuing UPDATEs (or
> trying to). Can you re-examine the situation? Perhaps try changing
> pg_hba.conf to be sure nobody is connecting. 9.0-style replication
> doesn't issue queries by itself.
I'm VERY sure nobody is connecting - the machine in question is behind a
firewall! In addition here's the netstat on it:

$ netstat -a -n|more
Active Internet connections (including servers)
Proto Recv-Q Send-Q Local Address Foreign Address (state)
tcp4 0 0 192.168.1.202.22 192.168.1.40.51232
ESTABLISHED
tcp4 0 0 192.168.1.202.61119 192.168.1.201.5432
ESTABLISHED
tcp4 0 0 *.5432 *.* LISTEN
tcp6 0 0 *.5432 *.* LISTEN
tcp4 0 0 *.514 *.* LISTEN
tcp4 0 0 127.0.0.1.25 *.* LISTEN
tcp4 0 0 *.22 *.* LISTEN
tcp6 0 0 *.22 *.* LISTEN
udp6 0 0 ::1.22165 ::1.22165
udp4 0 0 127.0.0.1.123 *.*
udp6 0 0 ::1.123 *.*
udp6 0 0 fe80:3::1.123 *.*
udp4 0 0 192.168.1.202.123 *.*
udp6 0 0 *.123 *.*
udp4 0 0 *.123 *.*
udp4 0 0 *.514 *.*
udp6 0 0 *.514 *.*

The only connection to a Postgresql server is to the master I am pulling
the replication from (201) No other connections - the listener is
there, but nobody's connected to it.

> Also, the UPDATEs look unsafe by themselves (replication or not). If two
> such updates are executed simultaneously, "views" might not be updated
> twice. Instead, try:
>
> update post set views = views + 1
> where number='140406' and toppost='1'
>
> Regards,
> Jeff Davis
That's actually ok - the update itself is a legitimate statement on the
master, posted to that table on a reply, and is part of a transaction.

I thought logshipping like this over TCP would present the actual WAL
changes (e.g. page changes) and was quite surprised when I saw what look
very much like actual statements in the logfile. A process status also
shows no postgres processes.

All of the real application connections are on a machine 1200 miles away
and behind pgpool, so if there WAS a connection it would be persistent.
It's not there (never mind that the clients don't have an entry in
pg_hba that would work, nor could they cross the firewall since there is
no port forwarding in the firewall to allow it.)

I'll investigate this further.

-- Karl

-- Karl