2

I had trouble in my environment which is related to autovacuum and now I think I understand how this occurs. However, this is kind of a rare issue and so I want to get some advice regarding this issue.

Our environment before the upgrade was:

  • RDS PostgreSQL 9.3, Multi-AZ and 4 Read Replica.
  • hot_standby_feedback = 1
  • max_standby_streaming_delay = -1
  • statement_timeout = 0 ( application also had no setting. )

I am a beginner to PostgreSQL (I've been working as a MySQL Admin) and had the task of upgrading to version 9.6. I should have done an investigation of the database beforehand, but couldn't. Then after the upgrade, lots of SELECT query waits occurred in the read replicas and I had no idea why this was happening.

I did some deeper investigation and I found that it was because of autovacuum. Here is the mailing archive of PostgreSQL that refers to the issue I am encountering:

WIP: long transactions on hot standby feedback replica / proof of concept

Our PostgreSQL was in the awful situation:
- There were long transactions (batch jobs that forgot to close transactions) that had kept locks on the 2 tables in the 9.3 version. I guess it kept on going more that one year at least. (Before I joined, there was nobody that be able to manage PostgreSQL.) Because of this, the 2 tables were hugely bloated. The actual amount of data size that the application is using is about 2GB although 2 tables had been grown to about 100GB each.
- I guess the two tables had not been the candidate of autovacuum because of the long transaction.
- Because the two tables had not been autovacuumed so long time, the tables had the huge number of live tuples.

As far as I know, when you do the major upgrade in RDS PostgreSQL, pg_upgrade works, and this includes concurrent vacuum operation. So after upgrade to 9.6, the two table had vacuumed but did not return free pages to OS. I used pgstattuple extension and this showed the two table had a huge amount of free pages. It showed 100GB as approx_free_space so it means almost all pages were free. This means the live tuple in the era of 9.3 became free pages because of concurrent vacuum which was done by pg_upgrade.

The two tables are always (I mean it 24h) accepting SELECT queries from application in the read replicas but not in the Master.

Here is an issue I had. When autovauum were running in Master against the two tables, a lots of SELECT queries in the read replicas were waiting for a ShareAccessLock. This lead to system fault because these queries never returned the result for a long time.

What's more, the error log just said

LOG: process <pid> still waiting for AccessShareLock on relation of <oid> of database <oid> after xxx ms at character xxxx ..." DETAIL: Process holding the lock: <pid> <pid> <pid> <pid> ... ( these pid were SELECT queries and lots of these were waiting)

As I showed, the error log did not tell "ERROR" or "FATAL" messages.

I was first confused how should I understand this log, because AccessShareLock shoud contend with other locks though we never did operation which gets any locks against two table while this was happening. I surely cheked error logs, pg_locks and pg_stat_activity and nothing that is suspious one that held any locks against the two table.

At the time this issue happened, I changed autovacuum parameter to false in Master to stop autovacuum and killed the autovacuum process against the two tables. And finally the wait query in the read replica disappeared.

As the link of mailing list archive says, autovacuum ( lazy_vacuum_rel ) tries to get an ExclusiveLock to truncate free pages in Master.

It gives up ExclusiveLock in master, but when WAL which includes ExclusiveLock query ships to read replicas, this WAL just replays without any hesitation even if PostgreSQL set with parameter I wrote at the begging. (I mean hot_standby_feedback!)

I assume that because of this, in our situation, that there were the huge amount of free pages, many free pages were being continuously truncated in Master, and lots of these were replaying and lots of SELECT queries were waiting in the read replicas.

As workaround, I set by alter table to not to be autovaccumed against the two table because I am afraid of happening this isuue again. Now autovaccum parameter got back to true.

So here is I want to discuses (and would like to know)

  1. Is this situation possibly happening? Is my guess correct?
  2. The error log told there were a lots of SELECT queries were waiting but did not tell what pid process hold AccessExclusiceLock against the two table. So I tried to find by checking pg_locks table but it cannot tell. I guess the reason why I could not get pid from pg_locks is that the process was bgwriter replaying WAL. I know we cannnot find bgwriter process from pg_stat_activity and I guess it also apply to pg_locks.
  3. Does pg_repack extension possibly trigger this issue?? I assume with the logic of pg_repack there is no chance of doing it.
  4. As far as I know, we cannot prevent from getting exclusive lock by autovacuum in read replica with this pattern. Also I think we cannot predict the timing this happen because I don't know the amount of freepages which triggers this AccessExclusiceLock situation, because it occurs over a long period. (I know my case is extreme.) So what would be the best practice to prevent this issue?

My idea is:

  • of course, never occurs long transaction. To do this, set statement_timeout and idle_in_transaction_session_timeout to a proper value.
  • keep watching or hopefully monitor value of free pages by using pgstattple.

I would be very appreciate if you give me any advice. Thanks.

  • How long does each individual select query last when there is no truncation replay being requested? – jjanes Apr 28 '18 at 12:01
  • We set log_min_duration_statement at 2 seconds and this query is recorded but not all the time. Also it goes up to 5 seconds at the maximam seconds. – eger Apr 30 '18 at 6:57
  • How long is any transaction on the replica? That is, how long is the longest statement that can potentially be doing the blocking, not just the one that is getting blocked? Do you have multi-statement transactions with a long gap between statements? – jjanes May 6 '18 at 16:33

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Browse other questions tagged or ask your own question.