Today we saw a couple behaviors in postgres we weren't expecting, and I'm not 
sure if there's something odd going on, or this is all business as usual and we 
never noticed before.

In steady-state, we have a 32-core box with a fair amount of ram acting as a 
job queue. It's constantly busy inserting, updating, and deleting a table that 
rarely has more than 100k rows. All access is done via indices, and query times 
are usually just a few ms. So that's all good. This server version is:

PostgreSQL 9.1.5 on x86_64-unknown-linux-gnu, compiled by gcc (Ubuntu/Linaro 
4.6.3-1ubuntu5) 4.6.3, 64-bit

This morning, one of the two servers that this streams wal files to for hot 
standby got locked up xlog replay pause mode. Nobody noticed this for several 
hours. The other server kept replicating just fine.

Within an hour, we had a query idle in transaction that was blocking other 
queries. This happens with our application sometimes, so we killed it and all 
the locks cleared out immediately. We didn't think much of it at the time.

However, soon after that, all other queries started taking longer. Even though 
there wasn't apparently any locking going on, queries were now taking almost 2 
seconds each, and the CPUs were pegged. Eventually, we noticed that if we 
rebuilt the index that was being used by that query, things would speed right 
back up again.... until autovacuum analyze kicked off, at which point things 
would immediately start taking 2 seconds again. Manually analyzing would not 
immediately cause things to get bad, but they would eventually revert back to 
being too slow. To be clear, even with the 2s query times, the proper index was 
still being used - it was just taking hundreds of ms, instead of a few ms. We 
tried increasing column stats to try to tease out any change in value 
distribution but this had no effect. So this was our first mystery.

Then we noticed that autovacuum wasn't clearing out tuples. Even odder, it 
appeared that when autovacuum started running, all the dead tuples would be 
listed as live tuples in pg_stat_user_tables, and after the vacuum completed, 
would go back to being dead tuples. Vacuum verbose showed that these tuples 
were not yet removable, even though there was no long transaction running. That 
was the second and third mysteries.

Finally, we found the wal replication problem and resume wal replay. All the 
problems listed above disappeared. So that's mystery #4.

My questions are:

1. Could wal replay on a hot streaming asynchronous slave really cause this? It 
certainly seems to have, and we do have hot_standby_feedback turned on, but we 
wouldn't have expected any symptoms from that which would have reduced the 
effectiveness of an index on the master.

2. Is it expected that during a vacuum, dead tuples show up as live tuples in 
pg_stat_user_tables?

3. Does a paused wal replay on an asynchronous slave count as a long running 
transaction, at least in terms of vacuuming out dead tuples on the master? If 
not, what else might keep vacuum from removing dead rows? All I could find on 
teh intarwebz was mention of long-running transactions, which pg_stat_activity 
and pg_locks didn't indicate.

4. What might cause autovacuum analyze to make an index perform worse 
immediately, when a manual vacuum analyze does not have the same affect? And 
I'm not talking about changing things so the planner doesn't use the index, but 
rather, having the index actually take longer. 

-- 
Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general

Reply via email to