pg.ddx.io pgsql-performance@postgresql.org mailing list archive
help / color / mirror / Atom feedStrange query stalls on replica in 9.3.9
6+ messages / 3 participants
[nested] [flat]
* Strange query stalls on replica in 9.3.9
@ 2015-08-13 17:09 Josh Berkus <josh@agliodbs.com>
2015-08-13 20:24 ` Re: Strange query stalls on replica in 9.3.9 Kevin Grittner <kgrittn@ymail.com>
2015-08-13 20:59 ` Re: Strange query stalls on replica in 9.3.9 Jeff Janes <jeff.janes@gmail.com>
0 siblings, 2 replies; 6+ messages in thread
From: Josh Berkus @ 2015-08-13 17:09 UTC (permalink / raw)
To: pgsql-performance
Setup:
* PostgreSQL 9.3.9
* 1 master, 1 replica
* Tiny database, under 0.5GB, completely cached in shared_buffers
* 90% read query traffic, which is handled by replica
* Traffic in the 1000's QPS.
The wierdness:
Periodically the master runs an "update all rows" query on the main
table in the database. When this update hits the replica via
replication stream, *some* (about 5%) of the queries which do seq scans
will stall for 22 to 32 seconds (these queries normally take about
75ms). Queries which do index scans seem not to be affected.
Thing is, the update all rows only takes 2.5 seconds to execute on the
master. So even if the update is blocking the seq scans on the replica
(and I can't see why it would), it should only block them for < 3 seconds.
Anyone seen anything like this?
--
Josh Berkus
PostgreSQL Experts Inc.
http://pgexperts.com
--
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: Strange query stalls on replica in 9.3.9
2015-08-13 17:09 Strange query stalls on replica in 9.3.9 Josh Berkus <josh@agliodbs.com>
@ 2015-08-13 20:24 ` Kevin Grittner <kgrittn@ymail.com>
2015-08-14 16:34 ` Re: Strange query stalls on replica in 9.3.9 Josh Berkus <josh@agliodbs.com>
1 sibling, 1 reply; 6+ messages in thread
From: Kevin Grittner @ 2015-08-13 20:24 UTC (permalink / raw)
To: Josh Berkus <josh@agliodbs.com>; pgsql-performance
Josh Berkus <josh@agliodbs.com> wrote:
> Periodically the master runs an "update all rows" query on the main
> table in the database. When this update hits the replica via
> replication stream, *some* (about 5%) of the queries which do seq scans
> will stall for 22 to 32 seconds (these queries normally take about
> 75ms). Queries which do index scans seem not to be affected.
>
> Thing is, the update all rows only takes 2.5 seconds to execute on the
> master. So even if the update is blocking the seq scans on the replica
> (and I can't see why it would), it should only block them for < 3 seconds.
Visibility hinting and/or hot pruning?
--
Kevin Grittner
EDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company
--
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: Strange query stalls on replica in 9.3.9
2015-08-13 17:09 Strange query stalls on replica in 9.3.9 Josh Berkus <josh@agliodbs.com>
2015-08-13 20:24 ` Re: Strange query stalls on replica in 9.3.9 Kevin Grittner <kgrittn@ymail.com>
@ 2015-08-14 16:34 ` Josh Berkus <josh@agliodbs.com>
2015-08-14 16:54 ` Re: Strange query stalls on replica in 9.3.9 Jeff Janes <jeff.janes@gmail.com>
0 siblings, 1 reply; 6+ messages in thread
From: Josh Berkus @ 2015-08-14 16:34 UTC (permalink / raw)
To: Kevin Grittner <kgrittn@ymail.com>; pgsql-performance; Jeff Janes <jeff.janes@gmail.com>
On 08/13/2015 01:24 PM, Kevin Grittner wrote:
>> Thing is, the update all rows only takes 2.5 seconds to execute on the
>> master. So even if the update is blocking the seq scans on the replica
>> (and I can't see why it would), it should only block them for < 3 seconds.
>
> Visibility hinting and/or hot pruning?
Unlikely; I can VACUUM FULL the entire database in 30 seconds. This
database is small. Jeff's answer seems more likely ...
On 08/13/2015 01:59 PM, Jeff Janes wrote: execute on the
> Once the commit of the whole-table update has replayed, the problem
> should go way instantly because at that point each backend doing the
> seqscan will find the the transaction has committed and so will set the
> hint bit that means all of the other seqscan backends that come after it
> can skip the proc array scan for that tuple.
Yes ... and given that the commit on the master took < 3 seconds, it's
not likely to take 30 seconds on the replica. That aside, the pattern
of behavior does look similar to the planner issue.
> So perhaps the commit of the whole-table update is delayed because the
> startup process as also getting bogged down on the same contended lock?
> I don't know how hard WAL replay hits the proc array lock.
I don't know; we don't have any visibility into the replay process, and
no way to tell if replay is waiting on some kind of lock. A regular
UPDATE should not block against any select activity on the replay, though.
Also, why would this affect *only* the query which does seq scans? Is
there some difference between seqscan and index scan here, or is it
simply because they take longer, and since this issue is timing-based,
they're more likely to be hit? Significantly, the seqscan query is also
the most complex query run against the replica, so maybe the seqscan is
irrelevant and it's being affected by planner issues?
--
Josh Berkus
PostgreSQL Experts Inc.
http://pgexperts.com
--
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: Strange query stalls on replica in 9.3.9
2015-08-13 17:09 Strange query stalls on replica in 9.3.9 Josh Berkus <josh@agliodbs.com>
2015-08-13 20:24 ` Re: Strange query stalls on replica in 9.3.9 Kevin Grittner <kgrittn@ymail.com>
2015-08-14 16:34 ` Re: Strange query stalls on replica in 9.3.9 Josh Berkus <josh@agliodbs.com>
@ 2015-08-14 16:54 ` Jeff Janes <jeff.janes@gmail.com>
2015-08-18 17:44 ` Re: Strange query stalls on replica in 9.3.9 Jeff Janes <jeff.janes@gmail.com>
0 siblings, 1 reply; 6+ messages in thread
From: Jeff Janes @ 2015-08-14 16:54 UTC (permalink / raw)
To: Josh Berkus <josh@agliodbs.com>; +Cc: Kevin Grittner <kgrittn@ymail.com>; pgsql-performance
On Fri, Aug 14, 2015 at 9:34 AM, Josh Berkus <josh@agliodbs.com> wrote:
>
> On 08/13/2015 01:59 PM, Jeff Janes wrote: execute on the
>
> > Once the commit of the whole-table update has replayed, the problem
> > should go way instantly because at that point each backend doing the
> > seqscan will find the the transaction has committed and so will set the
> > hint bit that means all of the other seqscan backends that come after it
> > can skip the proc array scan for that tuple.
>
> Yes ... and given that the commit on the master took < 3 seconds, it's
> not likely to take 30 seconds on the replica. That aside, the pattern
> of behavior does look similar to the planner issue.
>
Another thought. Who actually sets the hint bits on a replica?
Do the read-only processes on the replica which discovers a tuple to have
been securely committed set the hint bits?
My benchmarking suggests not.
Or does it wait for the hint bits to get set on master, and then for a
checkpoint to occur on the master, and then for that page to get changed
again and FPW to the log, and then for the log to get replayed? If so,
that explains why the issue doesn't clear up on the replica immediately
after the commit gets replayed.
>
> > So perhaps the commit of the whole-table update is delayed because the
> > startup process as also getting bogged down on the same contended lock?
> > I don't know how hard WAL replay hits the proc array lock.
>
> I don't know; we don't have any visibility into the replay process, and
> no way to tell if replay is waiting on some kind of lock. A regular
> UPDATE should not block against any select activity on the replay, though.
>
> Also, why would this affect *only* the query which does seq scans? Is
> there some difference between seqscan and index scan here, or is it
> simply because they take longer, and since this issue is timing-based,
> they're more likely to be hit?
An index scan only has to check the commit status of rows which meet the
index quals, which is presumably a small fraction of the rows.
A seq scan checks the visibility of every row first, before checking the
where clause.
Cheers,
Jeff
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: Strange query stalls on replica in 9.3.9
2015-08-13 17:09 Strange query stalls on replica in 9.3.9 Josh Berkus <josh@agliodbs.com>
2015-08-13 20:24 ` Re: Strange query stalls on replica in 9.3.9 Kevin Grittner <kgrittn@ymail.com>
2015-08-14 16:34 ` Re: Strange query stalls on replica in 9.3.9 Josh Berkus <josh@agliodbs.com>
2015-08-14 16:54 ` Re: Strange query stalls on replica in 9.3.9 Jeff Janes <jeff.janes@gmail.com>
@ 2015-08-18 17:44 ` Jeff Janes <jeff.janes@gmail.com>
0 siblings, 0 replies; 6+ messages in thread
From: Jeff Janes @ 2015-08-18 17:44 UTC (permalink / raw)
To: Josh Berkus <josh@agliodbs.com>; +Cc: Kevin Grittner <kgrittn@ymail.com>; pgsql-performance
On Fri, Aug 14, 2015 at 9:54 AM, Jeff Janes <jeff.janes@gmail.com> wrote:
> On Fri, Aug 14, 2015 at 9:34 AM, Josh Berkus <josh@agliodbs.com> wrote:
>
>>
>> On 08/13/2015 01:59 PM, Jeff Janes wrote: execute on the
>>
>> > Once the commit of the whole-table update has replayed, the problem
>> > should go way instantly because at that point each backend doing the
>> > seqscan will find the the transaction has committed and so will set the
>> > hint bit that means all of the other seqscan backends that come after it
>> > can skip the proc array scan for that tuple.
>>
>> Yes ... and given that the commit on the master took < 3 seconds, it's
>> not likely to take 30 seconds on the replica. That aside, the pattern
>> of behavior does look similar to the planner issue.
>>
>
> Another thought. Who actually sets the hint bits on a replica?
>
> Do the read-only processes on the replica which discovers a tuple to have
> been securely committed set the hint bits?
>
> My benchmarking suggests not.
>
The hint bits only get set if the commit lsn of the transaction of the
tuple being hinted (*not* the page lsn) thinks it has already been flushed
to WAL. On master the transaction commit record usually would have already
flushed its own WAL, or if async then wal writer is going to take care of
this fairly soon if nothing else gets to it first.
On the standby, it looks like the only thing that updates the
thinks-it-has-been-flushed-to marker (which is stored in the control file,
rather than memory) is either the eviction of a dirty buffer, or the
completion of a restartpoint. I could easily be wrong on that, though.
In any case, you empirically can have committed but unhintable tuples
hanging around for prolonged amounts of time on the standby. Perhaps
standbys need a wal writer process.
Cheers,
Jeff
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: Strange query stalls on replica in 9.3.9
2015-08-13 17:09 Strange query stalls on replica in 9.3.9 Josh Berkus <josh@agliodbs.com>
@ 2015-08-13 20:59 ` Jeff Janes <jeff.janes@gmail.com>
1 sibling, 0 replies; 6+ messages in thread
From: Jeff Janes @ 2015-08-13 20:59 UTC (permalink / raw)
To: Josh Berkus <josh@agliodbs.com>; +Cc: pgsql-performance
On Thu, Aug 13, 2015 at 10:09 AM, Josh Berkus <josh@agliodbs.com> wrote:
> Setup:
>
> * PostgreSQL 9.3.9
> * 1 master, 1 replica
> * Tiny database, under 0.5GB, completely cached in shared_buffers
> * 90% read query traffic, which is handled by replica
> * Traffic in the 1000's QPS.
>
> The wierdness:
>
> Periodically the master runs an "update all rows" query on the main
> table in the database. When this update hits the replica via
> replication stream, *some* (about 5%) of the queries which do seq scans
> will stall for 22 to 32 seconds (these queries normally take about
> 75ms). Queries which do index scans seem not to be affected.
>
> Thing is, the update all rows only takes 2.5 seconds to execute on the
> master. So even if the update is blocking the seq scans on the replica
> (and I can't see why it would), it should only block them for < 3 seconds.
>
> Anyone seen anything like this?
>
Sounds like another manifestation of this: "[PERFORM] Planner performance
extremely affected by an hanging transaction (20-30 times)?"
http://www.postgresql.org/message-id/CAMkU=1yy-YEQVvqj2xJitT1EFkyuFk7uTV_hrOMGyGMxpU=N+Q@mail.gmail....
Each backend that does a seqscan, for each tuple it scans which is not yet
resolved (which near the end of the bulk update is going to be nearly equal
to 2*reltuples, as every tuple has both an old and a new version so one
xmax from one and one xmin from the other must be checked), it has to lock
and scan the proc array lock to see if the tuple-inserting transaction has
committed yet. This creates profound contention on the lock. Every
scanning backend is looping over every other backend for every tuple
Once the commit of the whole-table update has replayed, the problem should
go way instantly because at that point each backend doing the seqscan will
find the the transaction has committed and so will set the hint bit that
means all of the other seqscan backends that come after it can skip the
proc array scan for that tuple.
So perhaps the commit of the whole-table update is delayed because the
startup process as also getting bogged down on the same contended lock? I
don't know how hard WAL replay hits the proc array lock.
Cheers,
Jeff
^ permalink raw reply [nested|flat] 6+ messages in thread
end of thread, other threads:[~2015-08-18 17:44 UTC | newest]
Thread overview: 6+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2015-08-13 17:09 Strange query stalls on replica in 9.3.9 Josh Berkus <josh@agliodbs.com>
2015-08-13 20:24 ` Kevin Grittner <kgrittn@ymail.com>
2015-08-14 16:34 ` Josh Berkus <josh@agliodbs.com>
2015-08-14 16:54 ` Jeff Janes <jeff.janes@gmail.com>
2015-08-18 17:44 ` Jeff Janes <jeff.janes@gmail.com>
2015-08-13 20:59 ` Jeff Janes <jeff.janes@gmail.com>
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox