pg.ddx.io pgsql-performance@postgresql.org mailing list archive
help / color / mirror / Atom feedPostgres Replaying WAL slowly
33+ messages / 9 participants
[nested] [flat]
* Postgres Replaying WAL slowly
@ 2014-06-29 08:14 Soni M <diptatapa@gmail.com>
0 siblings, 1 reply; 33+ messages in thread
From: Soni M @ 2014-06-29 08:14 UTC (permalink / raw)
To: pgsql-performance
Hello Everyone ...
We have 6 PG 9.1.12 installation, one master (Ubuntu 10.04), one slony
slave(Ubuntu 10.04), and four streaming replica (2 on Ubuntu 10.04 and 2 on
RHEL 6.5 (Santiago) which lies on different datacenter). All Ubuntu is on
same datacenter. Master send wal archive to slony slave.
This is the infrastructure description :
200Mbit link between data centers, esx 5.5 on hp blade chassis. proliant
gen 7 blades. postgres servers dedicated to esx hosts (no other vms on
those esx hosts). 3par disk backends with 4 and 8 Gbit fiber channel
connections. 10Gbit ethernet virtual connects on the hp chassis. cisco
fabric and network switches.
All postgres installed from Ubuntu/RHEL package.
Everything works fine until on Thursday we have high load on master, and
after that every streaming replica lag further behind the master. Even on
night and weekend where all server load is low. But the slony slave is OK
at all.
We thought it was due to network, so we decide to copy wal files to local
of a streaming server, and replaying wal from local. After PG restart, it
replays wal on a good speed about 3 seconds per wal file, but as the time
goes the speed decreasing. We had 30 seconds per wal file. The worst we get
is 3 minutes to replay 1 wal file.
The rate of wal produced from master is normal like usual. And also on
Thursday we had wal files on pg_xlog on streaming replica server, but no
other wal files.
This is the configuration :
SELECT name, current_setting(name)
FROM pg_settings
WHERE source NOT IN ('default', 'override');
name | current_setting
--------------------------------+---------------------------------------------------
application_name | psql
archive_command | /var/lib/postgresql/scripts/wal_archive
"%p" "%f"
archive_mode | on
checkpoint_completion_target | 0.7
checkpoint_segments | 30
client_encoding | UTF8
DateStyle | ISO, MDY
default_text_search_config | pg_catalog.english
effective_cache_size | 125GB
effective_io_concurrency | 3
external_pid_file | /var/run/postgresql/9.1-main.pid
hot_standby | on
hot_standby_feedback | on
lc_messages | en_US.UTF-8
lc_monetary | en_US.UTF-8
lc_numeric | en_US.UTF-8
lc_time | en_US.UTF-8
listen_addresses | *
log_checkpoints | on
log_connections | on
log_destination | csvlog
log_directory | pg_log
log_disconnections | on
log_filename | postgresql-%a.log
log_line_prefix | %t
log_lock_waits | on
log_rotation_age | 1d
log_rotation_size | 0
log_temp_files | 100kB
log_timezone | localtime
log_truncate_on_rotation | on
logging_collector | on
maintenance_work_mem | 1GB
max_connections | 750
max_locks_per_transaction | 900
max_pred_locks_per_transaction | 900
max_stack_depth | 2MB
max_wal_senders | 6
port | 5432
shared_buffers | 8GB
ssl | on
temp_buffers | 64MB
TimeZone | America/Chicago
unix_socket_directory | /var/run/postgresql
wal_keep_segments | 50
wal_level | hot_standby
work_mem | 256MB
(47 rows)
Thanks for any help
--
Regards,
Soni Maula Harriz
^ permalink raw reply [nested|flat] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-29 08:31 Heikki Linnakangas <hlinnakangas@vmware.com>
parent: Soni M <diptatapa@gmail.com>
0 siblings, 1 reply; 33+ messages in thread
From: Heikki Linnakangas @ 2014-06-29 08:31 UTC (permalink / raw)
To: Soni M <diptatapa@gmail.com>; pgsql-performance
On 06/29/2014 11:14 AM, Soni M wrote:
> Everything works fine until on Thursday we have high load on master, and
> after that every streaming replica lag further behind the master. Even on
> night and weekend where all server load is low. But the slony slave is OK
> at all.
What does 'top' on the standby say? Is the startup process using 100% of
(one) CPU replaying records, or is it waiting for I/O? How large is the
database, does it fit in RAM? Any clues in the system or PostgreSQL logs?
- Heikki
--
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] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-29 12:43 Soni M <diptatapa@gmail.com>
parent: Heikki Linnakangas <hlinnakangas@vmware.com>
0 siblings, 2 replies; 33+ messages in thread
From: Soni M @ 2014-06-29 12:43 UTC (permalink / raw)
To: Heikki Linnakangas <hlinnakangas@vmware.com>; +Cc: pgsql-performance
top and sar says 100% cpu usage of one core, no sign of I/O wait. The
database is 1.5TB in size. RAM in master is 145GB, on slave it's differ,
some has about 16GB another has 145GB also.
nothing suspicious on standby's postgres log.
on master's postgres log :
WARNING,01000,"pgstat wait timeout",,,,,,,,,""
ERROR,57014,"canceling autovacuum task",,,,,"automatic vacuum of
table ""consprod._consprod_replication.sl_event""",,,,""
ERROR,57014,"canceling statement due to statement timeout",,,,,,"
"PARSE",2014-06-26 00:39:35 CDT,91/0,0,ERROR,25P02,"current transaction is
aborted, commands ignored until end of transaction block",,,,,,"select
1",,,""
"could not receive data from client: Connection reset by peer",,,,,,,,,""
the log files is big anyway. if you can specify some pattern to look at the
log, that would really help.
On Sun, Jun 29, 2014 at 3:31 PM, Heikki Linnakangas <hlinnakangas@vmware.com
> wrote:
> On 06/29/2014 11:14 AM, Soni M wrote:
>
>> Everything works fine until on Thursday we have high load on master, and
>> after that every streaming replica lag further behind the master. Even on
>> night and weekend where all server load is low. But the slony slave is OK
>> at all.
>>
>
> What does 'top' on the standby say? Is the startup process using 100% of
> (one) CPU replaying records, or is it waiting for I/O? How large is the
> database, does it fit in RAM? Any clues in the system or PostgreSQL logs?
>
> - Heikki
>
>
--
Regards,
Soni Maula Harriz
^ permalink raw reply [nested|flat] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-29 13:05 Soni M <diptatapa@gmail.com>
parent: Soni M <diptatapa@gmail.com>
1 sibling, 0 replies; 33+ messages in thread
From: Soni M @ 2014-06-29 13:05 UTC (permalink / raw)
To: Heikki Linnakangas <hlinnakangas@vmware.com>; +Cc: pgsql-performance
Here's some data from standby (this is when replaying take 44seconds per
wal files):
2014-06-29 00:07:36.513 CDT,,,16682,,53af6f46.412a,44,,2014-06-28 20:43:34
CDT,,0,LOG,00000,"restartpoint complete: wrote 63187 buffers (3.0%); 0
transaction log file(s) added, 0 removed, 0 recycled; write=209.170 s,
sync=0.482 s, total=209.667 s; sync files=644, longest=0.036 s,
average=0.000 s",,,,,,,,,""
2014-06-29 00:07:36.513 CDT,,,16682,,53af6f46.412a,45,,2014-06-28 20:43:34
CDT,,0,LOG,00000,"recovery restart point at 27CE/170056A8","last completed
transaction was at log time 2014-06-27 13:39:00.542624-05",,,,,,,,""
2014-06-29 00:28:59.678 CDT,,,16682,,53af6f46.412a,47,,2014-06-28 20:43:34
CDT,,0,LOG,00000,"restartpoint complete: wrote 70942 buffers (3.4%); 0
transaction log file(s) added, 0 removed, 0 recycled; write=209.981 s,
sync=0.493 s, total=210.486 s; sync files=723, longest=0.156 s,
average=0.000 s",,,,,,,,,""
2014-06-29 00:28:59.678 CDT,,,16682,,53af6f46.412a,48,,2014-06-28 20:43:34
CDT,,0,LOG,00000,"recovery restart point at 27CE/35002678","last completed
transaction was at log time 2014-06-27 13:42:05.121121-05",,,,,,,,""
--
Regards,
Soni Maula Harriz
^ permalink raw reply [nested|flat] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 07:05 Heikki Linnakangas <hlinnakangas@vmware.com>
parent: Soni M <diptatapa@gmail.com>
1 sibling, 1 reply; 33+ messages in thread
From: Heikki Linnakangas @ 2014-06-30 07:05 UTC (permalink / raw)
To: Soni M <diptatapa@gmail.com>; +Cc: pgsql-performance
On 06/29/2014 03:43 PM, Soni M wrote:
> top and sar says 100% cpu usage of one core, no sign of I/O wait.
Hmm, I wonder what it's doing then... If you have "perf" installed on
the system, you can do "perf top" to get a quick overlook of where the
CPU time is spent.
- Heikki
--
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] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 14:46 Soni M <diptatapa@gmail.com>
parent: Heikki Linnakangas <hlinnakangas@vmware.com>
0 siblings, 1 reply; 33+ messages in thread
From: Soni M @ 2014-06-30 14:46 UTC (permalink / raw)
To: Heikki Linnakangas <hlinnakangas@vmware.com>; +Cc: pgsql-performance
Here's what 'perf top' said on streaming replica :
Samples: 26K of event 'cpu-clock', Event count (approx.): 19781
95.97% postgres [.] 0x00000000002210f3
0.41% perf [.] 0x000000000005f225
0.39% libc-2.12.so [.] __strstr_sse2
0.22% libc-2.12.so [.] memchr
0.22% [kernel] [k] kallsyms_expand_symbol
0.18% perf [.] symbols__insert
0.18% [kernel] [k] format_decode
0.15% libc-2.12.so [.] __GI___strcmp_ssse3
0.13% [kernel] [k] string
0.12% [kernel] [k] number
0.12% [kernel] [k] vsnprintf
0.12% libc-2.12.so [.] _IO_vfscanf
0.11% perf [.] dso__find_symbol
0.11% [kernel] [k] _spin_unlock_irqrestore
0.10% perf [.] hex2u64
0.10% postgres [.]
hash_search_with_hash_value
0.09% perf [.] rb_next
0.08% libc-2.12.so [.] memcpy
0.07% libc-2.12.so [.] __strchr_sse2
0.07% [kernel] [k] clear_page
0.06% [kernel] [k] strnlen
0.05% perf [.] perf_evsel__parse_sample
0.05% perf [.] rb_insert_color
0.05% [kernel] [k] pointer
On Mon, Jun 30, 2014 at 2:05 PM, Heikki Linnakangas <hlinnakangas@vmware.com
> wrote:
> On 06/29/2014 03:43 PM, Soni M wrote:
>
>> top and sar says 100% cpu usage of one core, no sign of I/O wait.
>>
>
> Hmm, I wonder what it's doing then... If you have "perf" installed on the
> system, you can do "perf top" to get a quick overlook of where the CPU time
> is spent.
>
> - Heikki
>
>
--
Regards,
Soni Maula Harriz
^ permalink raw reply [nested|flat] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 16:14 Heikki Linnakangas <hlinnakangas@vmware.com>
parent: Soni M <diptatapa@gmail.com>
0 siblings, 2 replies; 33+ messages in thread
From: Heikki Linnakangas @ 2014-06-30 16:14 UTC (permalink / raw)
To: Soni M <diptatapa@gmail.com>; +Cc: pgsql-performance
On 06/30/2014 05:46 PM, Soni M wrote:
> Here's what 'perf top' said on streaming replica :
>
> Samples: 26K of event 'cpu-clock', Event count (approx.): 19781
> 95.97% postgres [.] 0x00000000002210f3
Ok, so it's stuck doing something.. Can you get build with debug symbols
installed, so that we could see the function name?
- Heikki
--
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] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 17:04 Jeff Frost <jeff@pgexperts.com>
parent: Heikki Linnakangas <hlinnakangas@vmware.com>
1 sibling, 0 replies; 33+ messages in thread
From: Jeff Frost @ 2014-06-30 17:04 UTC (permalink / raw)
To: Heikki Linnakangas <hlinnakangas@vmware.com>; +Cc: Soni M <diptatapa@gmail.com>; pgsql-performance
On Jun 30, 2014, at 9:14 AM, Heikki Linnakangas <hlinnakangas@vmware.com> wrote:
> On 06/30/2014 05:46 PM, Soni M wrote:
>> Here's what 'perf top' said on streaming replica :
>>
>> Samples: 26K of event 'cpu-clock', Event count (approx.): 19781
>> 95.97% postgres [.] 0x00000000002210f3
>
> Ok, so it's stuck doing something.. Can you get build with debug symbols installed, so that we could see the function name?
> - Heikki
>
Looks like StandbyReleaseLocks:
Samples: 10K of event 'cpu-clock', Event count (approx.): 8507
89.21% postgres [.] StandbyReleaseLocks
0.89% libc-2.12.so [.] __strstr_sse2
0.83% perf [.] 0x000000000005f1e5
0.74% [kernel] [k] kallsyms_expand_symbol
0.52% libc-2.12.so [.] memchr
0.47% perf [.] symbols__insert
0.47% [kernel] [k] format_decode
--
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] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 17:14 Andres Freund <andres@2ndquadrant.com>
parent: Heikki Linnakangas <hlinnakangas@vmware.com>
1 sibling, 1 reply; 33+ messages in thread
From: Andres Freund @ 2014-06-30 17:14 UTC (permalink / raw)
To: Heikki Linnakangas <hlinnakangas@vmware.com>; +Cc: Soni M <diptatapa@gmail.com>; pgsql-performance
On 2014-06-30 19:14:24 +0300, Heikki Linnakangas wrote:
> On 06/30/2014 05:46 PM, Soni M wrote:
> >Here's what 'perf top' said on streaming replica :
> >
> >Samples: 26K of event 'cpu-clock', Event count (approx.): 19781
> > 95.97% postgres [.] 0x00000000002210f3
>
> Ok, so it's stuck doing something.. Can you get build with debug symbols
> installed, so that we could see the function name?
My guess it's a spinlock, probably xlogctl->info_lck via
RecoveryInProgress(). Unfortunately inline assembler doesn't always seem
to show up correctly in profiles...
What worked for me was to build with -fno-omit-frame-pointer - that
normally shows the callers, even if it can't generate a proper symbol
name.
Soni: Do you use Hot Standby? Are there connections active while you
have that problem? Any other processes with high cpu load?
Greetings,
Andres Freund
--
Andres Freund http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services
--
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] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 17:29 Soni M <diptatapa@gmail.com>
parent: Andres Freund <andres@2ndquadrant.com>
0 siblings, 1 reply; 33+ messages in thread
From: Soni M @ 2014-06-30 17:29 UTC (permalink / raw)
To: Andres Freund <andres@2ndquadrant.com>; +Cc: Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
On Tue, Jul 1, 2014 at 12:14 AM, Andres Freund <andres@2ndquadrant.com>
wrote:
>
> My guess it's a spinlock, probably xlogctl->info_lck via
> RecoveryInProgress(). Unfortunately inline assembler doesn't always seem
> to show up correctly in profiles...
>
> What worked for me was to build with -fno-omit-frame-pointer - that
> normally shows the callers, even if it can't generate a proper symbol
> name.
>
> Soni: Do you use Hot Standby? Are there connections active while you
> have that problem? Any other processes with high cpu load?
>
> Greetings,
>
> Andres Freund
>
> --
> Andres Freund http://www.2ndQuadrant.com/
> PostgreSQL Development, 24x7 Support, Training & Services
>
It is
96.62% postgres [.] StandbyReleaseLocks
as Jeff said. It runs quite long time, more than 5 minutes i think
i also use hot standby. we have 4 streaming replica, some of them has
active connection some has not. this issue has last more than 4 days. On
one of the standby, above postgres process is the only process that consume
high cpu load.
--
Regards,
Soni Maula Harriz
^ permalink raw reply [nested|flat] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 18:34 Jeff Frost <jeff@pgexperts.com>
parent: Soni M <diptatapa@gmail.com>
0 siblings, 2 replies; 33+ messages in thread
From: Jeff Frost @ 2014-06-30 18:34 UTC (permalink / raw)
To: Soni M <diptatapa@gmail.com>; +Cc: Andres Freund <andres@2ndquadrant.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
On Jun 30, 2014, at 10:29 AM, Soni M <diptatapa@gmail.com> wrote:
>
>
>
> On Tue, Jul 1, 2014 at 12:14 AM, Andres Freund <andres@2ndquadrant.com> wrote:
>
> My guess it's a spinlock, probably xlogctl->info_lck via
> RecoveryInProgress(). Unfortunately inline assembler doesn't always seem
> to show up correctly in profiles...
>
> What worked for me was to build with -fno-omit-frame-pointer - that
> normally shows the callers, even if it can't generate a proper symbol
> name.
>
> Soni: Do you use Hot Standby? Are there connections active while you
> have that problem? Any other processes with high cpu load?
>
> Greetings,
>
> Andres Freund
>
> --
> Andres Freund http://www.2ndQuadrant.com/
> PostgreSQL Development, 24x7 Support, Training & Services
>
> It is
> 96.62% postgres [.] StandbyReleaseLocks
> as Jeff said. It runs quite long time, more than 5 minutes i think
>
> i also use hot standby. we have 4 streaming replica, some of them has active connection some has not. this issue has last more than 4 days. On one of the standby, above postgres process is the only process that consume high cpu load.
compiled with -fno-omit-frame-pointer doesn't yield much more info:
76.24% postgres [.] StandbyReleaseLocks
2.64% libcrypto.so.1.0.1e [.] md5_block_asm_data_order
2.19% libcrypto.so.1.0.1e [.] RC4
2.17% postgres [.] RecordIsValid
1.20% [kernel] [k] copy_user_generic_unrolled
1.18% [kernel] [k] _spin_unlock_irqrestore
0.97% [vmxnet3] [k] vmxnet3_poll_rx_only
0.87% [kernel] [k] __do_softirq
0.77% [vmxnet3] [k] vmxnet3_xmit_frame
0.69% postgres [.] hash_search_with_hash_value
0.68% [kernel] [k] fin
However, this server started progressing through the WAL files quite a bit better before I finished compiling, so we'll leave it running with this version and see if there's more info available the next time it starts replaying slowly.
^ permalink raw reply [nested|flat] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 18:39 Andres Freund <andres@2ndquadrant.com>
parent: Jeff Frost <jeff@pgexperts.com>
1 sibling, 1 reply; 33+ messages in thread
From: Andres Freund @ 2014-06-30 18:39 UTC (permalink / raw)
To: Jeff Frost <jeff@pgexperts.com>; +Cc: Soni M <diptatapa@gmail.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
On 2014-06-30 11:34:52 -0700, Jeff Frost wrote:
> On Jun 30, 2014, at 10:29 AM, Soni M <diptatapa@gmail.com> wrote:
> > It is
> > 96.62% postgres [.] StandbyReleaseLocks
> > as Jeff said. It runs quite long time, more than 5 minutes i think
> >
> > i also use hot standby. we have 4 streaming replica, some of them has active connection some has not. this issue has last more than 4 days. On one of the standby, above postgres process is the only process that consume high cpu load.
>
> compiled with -fno-omit-frame-pointer doesn't yield much more info:
You'd need to do perf record -ga instead of perf record -a to see
additional information.
But:
> 76.24% postgres [.] StandbyReleaseLocks
already is quite helpful.
What are you doing on that system? Is there anything requiring large
amounts of access exclusive locks on the primary? Possibly large amounts
of temporary relations?
Greetings,
Andres Freund
--
Andres Freund http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services
--
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] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 18:40 Pavel Stehule <pavel.stehule@gmail.com>
parent: Jeff Frost <jeff@pgexperts.com>
1 sibling, 0 replies; 33+ messages in thread
From: Pavel Stehule @ 2014-06-30 18:40 UTC (permalink / raw)
To: Jeff Frost <jeff@pgexperts.com>; +Cc: Soni M <diptatapa@gmail.com>; Andres Freund <andres@2ndquadrant.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
2014-06-30 20:34 GMT+02:00 Jeff Frost <jeff@pgexperts.com>:
> On Jun 30, 2014, at 10:29 AM, Soni M <diptatapa@gmail.com> wrote:
>
>
>
>
> On Tue, Jul 1, 2014 at 12:14 AM, Andres Freund <andres@2ndquadrant.com>
> wrote:
>
>>
>> My guess it's a spinlock, probably xlogctl->info_lck via
>> RecoveryInProgress(). Unfortunately inline assembler doesn't always seem
>> to show up correctly in profiles...
>>
>>
For this kind of issues a systemtap or dtrace can be useful
http://postgres.cz/wiki/Monitorov%C3%A1n%C3%AD_lwlocku_pomoc%C3%AD_systemtapu
you can identify what locking is a problem - please, use a google translate
Regards
Pavel
> What worked for me was to build with -fno-omit-frame-pointer - that
>> normally shows the callers, even if it can't generate a proper symbol
>> name.
>>
>> Soni: Do you use Hot Standby? Are there connections active while you
>> have that problem? Any other processes with high cpu load?
>>
>> Greetings,
>>
>> Andres Freund
>>
>> --
>> Andres Freund http://www.2ndQuadrant.com/
>> <http://www.2ndquadrant.com/;
>> PostgreSQL Development, 24x7 Support, Training & Services
>>
>
> It is
> 96.62% postgres [.] StandbyReleaseLocks
> as Jeff said. It runs quite long time, more than 5 minutes i think
>
> i also use hot standby. we have 4 streaming replica, some of them has
> active connection some has not. this issue has last more than 4 days. On
> one of the standby, above postgres process is the only process that consume
> high cpu load.
>
>
> compiled with -fno-omit-frame-pointer doesn't yield much more info:
>
> 76.24% postgres [.] StandbyReleaseLocks
> 2.64% libcrypto.so.1.0.1e [.]
> md5_block_asm_data_order
> 2.19% libcrypto.so.1.0.1e [.] RC4
> 2.17% postgres [.] RecordIsValid
> 1.20% [kernel] [k]
> copy_user_generic_unrolled
> 1.18% [kernel] [k] _spin_unlock_irqrestore
> 0.97% [vmxnet3] [k] vmxnet3_poll_rx_only
> 0.87% [kernel] [k] __do_softirq
> 0.77% [vmxnet3] [k] vmxnet3_xmit_frame
> 0.69% postgres [.]
> hash_search_with_hash_value
> 0.68% [kernel] [k] fin
>
> However, this server started progressing through the WAL files quite a bit
> better before I finished compiling, so we'll leave it running with this
> version and see if there's more info available the next time it starts
> replaying slowly.
>
>
>
^ permalink raw reply [nested|flat] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 19:17 Jeff Frost <jeff@pgexperts.com>
parent: Andres Freund <andres@2ndquadrant.com>
0 siblings, 1 reply; 33+ messages in thread
From: Jeff Frost @ 2014-06-30 19:17 UTC (permalink / raw)
To: Andres Freund <andres@2ndquadrant.com>; +Cc: Soni M <diptatapa@gmail.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
On Jun 30, 2014, at 11:39 AM, Andres Freund <andres@2ndquadrant.com> wrote:
> On 2014-06-30 11:34:52 -0700, Jeff Frost wrote:
>> On Jun 30, 2014, at 10:29 AM, Soni M <diptatapa@gmail.com> wrote:
>
>>> It is
>>> 96.62% postgres [.] StandbyReleaseLocks
>>> as Jeff said. It runs quite long time, more than 5 minutes i think
>>>
>>> i also use hot standby. we have 4 streaming replica, some of them has active connection some has not. this issue has last more than 4 days. On one of the standby, above postgres process is the only process that consume high cpu load.
>>
>> compiled with -fno-omit-frame-pointer doesn't yield much more info:
>
> You'd need to do perf record -ga instead of perf record -a to see
> additional information.
>
Ah! That's right.
Here's how that looks:
Samples: 473K of event 'cpu-clock', Event count (approx.): 473738
+ 68.42% init [kernel.kallsyms] [k] native_safe_halt
+ 26.07% postgres postgres [.] StandbyReleaseLocks
+ 2.82% swapper [kernel.kallsyms] [k] native_safe_halt
+ 0.19% ssh libcrypto.so.1.0.1e [.] md5_block_asm_data_order
+ 0.19% postgres postgres [.] RecordIsValid
+ 0.16% ssh libcrypto.so.1.0.1e [.] RC4
+ 0.10% postgres postgres [.] hash_search_with_hash_value
+ 0.06% postgres [kernel.kallsyms] [k] _spin_unlock_irqrestore
+ 0.05% init [vmxnet3] [k] vmxnet3_poll_rx_only
+ 0.04% postgres [kernel.kallsyms] [k] copy_user_generic_unrolled
+ 0.04% init [kernel.kallsyms] [k] finish_task_switch
+ 0.04% init [kernel.kallsyms] [k] __do_softirq
+ 0.04% ssh [kernel.kallsyms] [k] _spin_unlock_irqrestore
+ 0.04% ssh [vmxnet3] [k] vmxnet3_xmit_frame
+ 0.03% postgres postgres [.] PinBuffer
+ 0.03% init [vmxnet3] [k] vmxnet3_xmit_frame
+ 0.03% ssh [kernel.kallsyms] [k] copy_user_generic_unrolled
+ 0.03% postgres postgres [.] XLogReadBufferExtended
+ 0.03% ssh ssh [.] 0x000000000002aa07
+ 0.03% init [kernel.kallsyms] [k] _spin_unlock_irqrestore
+ 0.03% ssh [vmxnet3] [k] vmxnet3_poll_rx_only
+ 0.02% ssh [kernel.kallsyms] [k] __do_softirq
+ 0.02% postgres libc-2.12.so [.] _wordcopy_bwd_dest_aligned
+ 0.02% postgres postgres [.] mdnblocks
+ 0.02% ssh libcrypto.so.1.0.1e [.] 0x00000000000e25a1
+ 0.02% scp [kernel.kallsyms] [k] copy_user_generic_unrolled
+ 0.02% ssh libc-2.12.so [.] memcpy
+ 0.02% postgres libc-2.12.so [.] memcpy
> But:
>
>> 76.24% postgres [.] StandbyReleaseLocks
>
> already is quite helpful.
>
> What are you doing on that system? Is there anything requiring large
> amounts of access exclusive locks on the primary? Possibly large amounts
> of temporary relations?
The last time we did a 100% logging run, the peak temp table creation was something like 120k/hr, but the replicas seemed able to keep up with that just fine.
Hopefully Soni can answer whether that has increased significantly since May.
--
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] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 19:25 Jeff Frost <jeff@pgexperts.com>
parent: Jeff Frost <jeff@pgexperts.com>
0 siblings, 1 reply; 33+ messages in thread
From: Jeff Frost @ 2014-06-30 19:25 UTC (permalink / raw)
To: Andres Freund <andres@2ndquadrant.com>; +Cc: Soni M <diptatapa@gmail.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
On Jun 30, 2014, at 12:17 PM, Jeff Frost <jeff@pgexperts.com> wrote:
>>
>> already is quite helpful.
>>
>> What are you doing on that system? Is there anything requiring large
>> amounts of access exclusive locks on the primary? Possibly large amounts
>> of temporary relations?
>
>
> The last time we did a 100% logging run, the peak temp table creation was something like 120k/hr, but the replicas seemed able to keep up with that just fine.
>
Sampling pg_locks on the primary shows ~50 locks with ExclusiveLock mode:
mode | count
--------------------------+-------
AccessExclusiveLock | 11
AccessShareLock | 2089
ExclusiveLock | 46
RowExclusiveLock | 81
RowShareLock | 17
ShareLock | 4
ShareUpdateExclusiveLock | 5
Seems to be relatively consistent. Of course, it's hard to say what it looked like back when the issue began.
^ permalink raw reply [nested|flat] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 19:32 Tom Lane <tgl@sss.pgh.pa.us>
parent: Jeff Frost <jeff@pgexperts.com>
0 siblings, 1 reply; 33+ messages in thread
From: Tom Lane @ 2014-06-30 19:32 UTC (permalink / raw)
To: Jeff Frost <jeff@pgexperts.com>; +Cc: Andres Freund <andres@2ndquadrant.com>; Soni M <diptatapa@gmail.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
Jeff Frost <jeff@pgexperts.com> writes:
> Sampling pg_locks on the primary shows ~50 locks with ExclusiveLock mode:
> mode | count
> --------------------------+-------
> AccessExclusiveLock | 11
> AccessShareLock | 2089
> ExclusiveLock | 46
> RowExclusiveLock | 81
> RowShareLock | 17
> ShareLock | 4
> ShareUpdateExclusiveLock | 5
That's not too helpful if you don't pay attention to what the lock is on;
it's likely that all the ExclusiveLocks are on transactions' own XIDs,
which isn't relevant to the standby's behavior. The AccessExclusiveLocks
are probably interesting though --- you should look to see what those
are on.
regards, tom lane
--
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] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 19:42 Jeff Frost <jeff@pgexperts.com>
parent: Tom Lane <tgl@sss.pgh.pa.us>
0 siblings, 1 reply; 33+ messages in thread
From: Jeff Frost @ 2014-06-30 19:42 UTC (permalink / raw)
To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: Andres Freund <andres@2ndquadrant.com>; Soni M <diptatapa@gmail.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
On Jun 30, 2014, at 12:32 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Jeff Frost <jeff@pgexperts.com> writes:
>> Sampling pg_locks on the primary shows ~50 locks with ExclusiveLock mode:
>
>> mode | count
>> --------------------------+-------
>> AccessExclusiveLock | 11
>> AccessShareLock | 2089
>> ExclusiveLock | 46
>> RowExclusiveLock | 81
>> RowShareLock | 17
>> ShareLock | 4
>> ShareUpdateExclusiveLock | 5
>
> That's not too helpful if you don't pay attention to what the lock is on;
> it's likely that all the ExclusiveLocks are on transactions' own XIDs,
> which isn't relevant to the standby's behavior. The AccessExclusiveLocks
> are probably interesting though --- you should look to see what those
> are on.
You're right about the ExclusiveLocks.
Here's how the AccessExclusiveLocks look:
locktype | database | relation | page | tuple | virtualxid | transactionid | classid | objid | objsubid | virtualtransaction | pid | mode | granted
----------+----------+------------+------+-------+------------+---------------+---------+------------+----------+--------------------+-------+---------------------+---------
relation | 111285 | 3245291551 | | | | | | | | 233/170813 | 23509 | AccessExclusiveLock | t
relation | 111285 | 3245292820 | | | | | | | | 5/22498235 | 23427 | AccessExclusiveLock | t
relation | 111285 | 3245292833 | | | | | | | | 173/1723993 | 23407 | AccessExclusiveLock | t
relation | 111285 | 3245287874 | | | | | | | | 133/3818415 | 23348 | AccessExclusiveLock | t
relation | 111285 | 3245292836 | | | | | | | | 173/1723993 | 23407 | AccessExclusiveLock | t
relation | 111285 | 3245292774 | | | | | | | | 5/22498235 | 23427 | AccessExclusiveLock | t
relation | 111285 | 3245292734 | | | | | | | | 5/22498235 | 23427 | AccessExclusiveLock | t
relation | 111285 | 3245292827 | | | | | | | | 173/1723993 | 23407 | AccessExclusiveLock | t
relation | 111285 | 3245288540 | | | | | | | | 133/3818415 | 23348 | AccessExclusiveLock | t
relation | 111285 | 3245292773 | | | | | | | | 5/22498235 | 23427 | AccessExclusiveLock | t
relation | 111285 | 3245292775 | | | | | | | | 5/22498235 | 23427 | AccessExclusiveLock | t
relation | 111285 | 3245292743 | | | | | | | | 5/22498235 | 23427 | AccessExclusiveLock | t
relation | 111285 | 3245292751 | | | | | | | | 5/22498235 | 23427 | AccessExclusiveLock | t
relation | 111285 | 3245288669 | | | | | | | | 133/3818415 | 23348 | AccessExclusiveLock | t
relation | 111285 | 3245292817 | | | | | | | | 5/22498235 | 23427 | AccessExclusiveLock | t
relation | 111285 | 3245288657 | | | | | | | | 133/3818415 | 23348 | AccessExclusiveLock | t
object | 111285 | | | | | | 2615 | 1246019760 | 0 | 233/170813 | 23509 | AccessExclusiveLock | t
relation | 111285 | 3245292746 | | | | | | | | 5/22498235 | 23427 | AccessExclusiveLock | t
relation | 111285 | 3245287876 | | | | | | | | 133/3818415 | 23348 | AccessExclusiveLock | t
relation | 111285 | 3245292739 | | | | | | | | 5/22498235 | 23427 | AccessExclusiveLock | t
relation | 111285 | 3245292826 | | | | | | | | 5/22498235 | 23427 | AccessExclusiveLock | t
relation | 111285 | 3245292825 | | | | | | | | 5/22498235 | 23427 | AccessExclusiveLock | t
relation | 111285 | 3245292832 | | | | | | | | 173/1723993 | 23407 | AccessExclusiveLock | t
relation | 111285 | 3245292740 | | | | | | | | 5/22498235 | 23427 | AccessExclusiveLock | t
relation | 111285 | 3245287871 | | | | | | | | 133/3818415 | 23348 | AccessExclusiveLock | t
(25 rows)
And if you go fishing in pg_class for any of the oids, you don't find anything:
SELECT s.procpid,
s.query_start,
n.nspname,
c.relname,
l.mode,
l.granted,
s.current_query
FROM pg_locks l,
pg_class c,
pg_stat_activity s,
pg_namespace n
WHERE l.relation = c.oid
AND l.pid = s.procpid
AND c.relnamespace = n.oid
AND l.mode = 'AccessExclusiveLock';
procpid | query_start | nspname | relname | mode | granted | current_query
---------+-------------+---------+---------+------+---------+---------------
(0 rows)
Temp tables maybe?
--
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] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 19:54 Matheus de Oliveira <matioli.matheus@gmail.com>
parent: Jeff Frost <jeff@pgexperts.com>
0 siblings, 1 reply; 33+ messages in thread
From: Matheus de Oliveira @ 2014-06-30 19:54 UTC (permalink / raw)
To: Jeff Frost <jeff@pgexperts.com>; +Cc: Tom Lane <tgl@sss.pgh.pa.us>; Andres Freund <andres@2ndquadrant.com>; Soni M <diptatapa@gmail.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
On Mon, Jun 30, 2014 at 4:42 PM, Jeff Frost <jeff@pgexperts.com> wrote:
> And if you go fishing in pg_class for any of the oids, you don't find
> anything:
That is probably because you are connected in the wrong database. Once you
connect to the database of interest, you don't even need to query pg_class,
just cast relation attribute to regclass:
SELECT relation::regclass, ...
FROM pg_locks WHERE database = (SELECT oid FROM pg_database WHERE
datname = current_database());
Regards,
--
Matheus de Oliveira
Analista de Banco de Dados
Dextra Sistemas - MPS.Br nÃvel F!
www.dextra.com.br/postgres
^ permalink raw reply [nested|flat] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 19:57 Jeff Frost <jeff@pgexperts.com>
parent: Matheus de Oliveira <matioli.matheus@gmail.com>
0 siblings, 1 reply; 33+ messages in thread
From: Jeff Frost @ 2014-06-30 19:57 UTC (permalink / raw)
To: Matheus de Oliveira <matioli.matheus@gmail.com>; +Cc: Tom Lane <tgl@sss.pgh.pa.us>; Andres Freund <andres@2ndquadrant.com>; Soni M <diptatapa@gmail.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
On Jun 30, 2014, at 12:54 PM, Matheus de Oliveira <matioli.matheus@gmail.com> wrote:
>
> On Mon, Jun 30, 2014 at 4:42 PM, Jeff Frost <jeff@pgexperts.com> wrote:
> And if you go fishing in pg_class for any of the oids, you don't find anything:
>
> That is probably because you are connected in the wrong database. Once you connect to the database of interest, you don't even need to query pg_class, just cast relation attribute to regclass:
>
> SELECT relation::regclass, ...
> FROM pg_locks WHERE database = (SELECT oid FROM pg_database WHERE datname = current_database());
>
Yah, i thought about that too, but verified I am in the correct DB. Just for clarity sake:
SELECT relation::regclass
FROM pg_locks WHERE database = (SELECT oid FROM pg_database WHERE datname = current_database()) and mode = 'AccessExclusiveLock';
relation
------------
3245508214
3245508273
3245508272
3245508257
3245508469
3245508274
3245508373
3245508468
3245508210
3245508463
3245508205
3245508260
3245508265
3245508434
(16 rows)=
^ permalink raw reply [nested|flat] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 20:15 Andres Freund <andres@2ndquadrant.com>
parent: Jeff Frost <jeff@pgexperts.com>
0 siblings, 1 reply; 33+ messages in thread
From: Andres Freund @ 2014-06-30 20:15 UTC (permalink / raw)
To: Jeff Frost <jeff@pgexperts.com>; +Cc: Matheus de Oliveira <matioli.matheus@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; Soni M <diptatapa@gmail.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
On 2014-06-30 12:57:56 -0700, Jeff Frost wrote:
>
> On Jun 30, 2014, at 12:54 PM, Matheus de Oliveira <matioli.matheus@gmail.com> wrote:
>
> >
> > On Mon, Jun 30, 2014 at 4:42 PM, Jeff Frost <jeff@pgexperts.com> wrote:
> > And if you go fishing in pg_class for any of the oids, you don't find anything:
> >
> > That is probably because you are connected in the wrong database. Once you connect to the database of interest, you don't even need to query pg_class, just cast relation attribute to regclass:
> >
> > SELECT relation::regclass, ...
> > FROM pg_locks WHERE database = (SELECT oid FROM pg_database WHERE datname = current_database());
> >
>
> Yah, i thought about that too, but verified I am in the correct DB. Just for clarity sake:
So these are probably relations created in uncommitted
transactions. Possibly ON COMMIT DROP temp tables?
Greetings,
Andres Freund
--
Andres Freund http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services
--
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] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 20:21 Jeff Frost <jeff@pgexperts.com>
parent: Andres Freund <andres@2ndquadrant.com>
0 siblings, 1 reply; 33+ messages in thread
From: Jeff Frost @ 2014-06-30 20:21 UTC (permalink / raw)
To: Andres Freund <andres@2ndquadrant.com>; +Cc: Matheus de Oliveira <matioli.matheus@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; Soni M <diptatapa@gmail.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
On Jun 30, 2014, at 1:15 PM, Andres Freund <andres@2ndquadrant.com> wrote:
> On 2014-06-30 12:57:56 -0700, Jeff Frost wrote:
>>
>> On Jun 30, 2014, at 12:54 PM, Matheus de Oliveira <matioli.matheus@gmail.com> wrote:
>>
>>>
>>> On Mon, Jun 30, 2014 at 4:42 PM, Jeff Frost <jeff@pgexperts.com> wrote:
>>> And if you go fishing in pg_class for any of the oids, you don't find anything:
>>>
>>> That is probably because you are connected in the wrong database. Once you connect to the database of interest, you don't even need to query pg_class, just cast relation attribute to regclass:
>>>
>>> SELECT relation::regclass, ...
>>> FROM pg_locks WHERE database = (SELECT oid FROM pg_database WHERE datname = current_database());
>>>
>>
>> Yah, i thought about that too, but verified I am in the correct DB. Just for clarity sake:
>
> So these are probably relations created in uncommitted
> transactions. Possibly ON COMMIT DROP temp tables?
That would make sense. There are definitely quite a few of those being used.
Another item of note is the system catalogs are quite bloated:
schemaname | tablename | tbloat | wastedmb | idxbloat | wastedidxmb
------------+--------------+--------+----------+----------+-------------
pg_catalog | pg_attribute | 3945 | 106.51 | 2770 | 611.28
pg_catalog | pg_class | 8940 | 45.26 | 4420 | 47.89
pg_catalog | pg_type | 4921 | 18.45 | 5850 | 81.16
pg_catalog | pg_depend | 933 | 10.23 | 11730 | 274.37
pg_catalog | pg_index | 3429 | 8.36 | 3920 | 24.24
pg_catalog | pg_shdepend | 983 | 2.67 | 9360 | 30.56
(6 rows)
Would that cause the replica to spin on StandbyReleaseLocks?
^ permalink raw reply [nested|flat] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 20:39 Tom Lane <tgl@sss.pgh.pa.us>
parent: Jeff Frost <jeff@pgexperts.com>
0 siblings, 1 reply; 33+ messages in thread
From: Tom Lane @ 2014-06-30 20:39 UTC (permalink / raw)
To: Jeff Frost <jeff@pgexperts.com>; +Cc: Andres Freund <andres@2ndquadrant.com>; Matheus de Oliveira <matioli.matheus@gmail.com>; Soni M <diptatapa@gmail.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
Jeff Frost <jeff@pgexperts.com> writes:
> On Jun 30, 2014, at 1:15 PM, Andres Freund <andres@2ndquadrant.com> wrote:
>> So these are probably relations created in uncommitted
>> transactions. Possibly ON COMMIT DROP temp tables?
> That would make sense. There are definitely quite a few of those being used.
Uh-huh. I doubt that the mechanism that handles propagation of
AccessExclusiveLocks to the standby is smart enough to ignore locks
on temp tables :-(
> Another item of note is the system catalogs are quite bloated:
> Would that cause the replica to spin on StandbyReleaseLocks?
AFAIK, no. It's an unsurprising consequence of heavy use of short-lived
temp tables though.
So it seems like we have a candidate explanation. I'm a bit surprised
that StandbyReleaseLocks would get this slow if there are only a dozen
AccessExclusiveLocks in place at any one time, though. Perhaps that
was a low point and there are often many more?
regards, tom lane
--
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] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 20:46 Jeff Frost <jeff@pgexperts.com>
parent: Tom Lane <tgl@sss.pgh.pa.us>
0 siblings, 1 reply; 33+ messages in thread
From: Jeff Frost @ 2014-06-30 20:46 UTC (permalink / raw)
To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: Andres Freund <andres@2ndquadrant.com>; Matheus de Oliveira <matioli.matheus@gmail.com>; Soni M <diptatapa@gmail.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
On Jun 30, 2014, at 1:39 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>
>
>> Another item of note is the system catalogs are quite bloated:
>> Would that cause the replica to spin on StandbyReleaseLocks?
>
> AFAIK, no. It's an unsurprising consequence of heavy use of short-lived
> temp tables though.
>
Yah, this has been an issue in the past, so we tend to cluster them regularly during off-hours to minimize the issue.
> So it seems like we have a candidate explanation. I'm a bit surprised
> that StandbyReleaseLocks would get this slow if there are only a dozen
> AccessExclusiveLocks in place at any one time, though. Perhaps that
> was a low point and there are often many more?
>
>
Entirely possible that it was a low point. We'll set up some monitoring to track the number of AccessExclusiveLocks and see how much variance there is throughout the day.
--
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] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 21:52 Jeff Frost <jeff@pgexperts.com>
parent: Jeff Frost <jeff@pgexperts.com>
0 siblings, 1 reply; 33+ messages in thread
From: Jeff Frost @ 2014-06-30 21:52 UTC (permalink / raw)
To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: Andres Freund <andres@2ndquadrant.com>; Matheus de Oliveira <matioli.matheus@gmail.com>; Soni M <diptatapa@gmail.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
On Jun 30, 2014, at 1:46 PM, Jeff Frost <jeff@pgexperts.com> wrote:
>> So it seems like we have a candidate explanation. I'm a bit surprised
>> that StandbyReleaseLocks would get this slow if there are only a dozen
>> AccessExclusiveLocks in place at any one time, though. Perhaps that
>> was a low point and there are often many more?
>>
>>
>
> Entirely possible that it was a low point. We'll set up some monitoring to track the number of AccessExclusiveLocks and see how much variance there is throughout the day.
Since we turned on the monitoring for that, we had a peak of 13,550 AccessExclusiveLocks. So far most of the samples have been in the double digit, with that and two other outliers: 6,118 and 12,747.=
^ permalink raw reply [nested|flat] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 23:04 Tom Lane <tgl@sss.pgh.pa.us>
parent: Jeff Frost <jeff@pgexperts.com>
0 siblings, 2 replies; 33+ messages in thread
From: Tom Lane @ 2014-06-30 23:04 UTC (permalink / raw)
To: Jeff Frost <jeff@pgexperts.com>; +Cc: Andres Freund <andres@2ndquadrant.com>; Matheus de Oliveira <matioli.matheus@gmail.com>; Soni M <diptatapa@gmail.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
Jeff Frost <jeff@pgexperts.com> writes:
>>> So it seems like we have a candidate explanation. I'm a bit surprised
>>> that StandbyReleaseLocks would get this slow if there are only a dozen
>>> AccessExclusiveLocks in place at any one time, though. Perhaps that
>>> was a low point and there are often many more?
> Since we turned on the monitoring for that, we had a peak of 13,550
> AccessExclusiveLocks.
Ah ... that's more like a number I can believe something would have
trouble coping with. Did you see a noticeable slowdown with this?
Now that we've seen that number, of course it's possible there was an
even higher peak occurring when you saw the trouble.
Perhaps there's an O(N^2) behavior in StandbyReleaseLocks, or maybe
it just takes awhile to handle that many locks.
Did you check whether the locks were all on temp tables of the
ON COMMIT DROP persuasion?
regards, tom lane
--
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] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 23:17 Andres Freund <andres@2ndquadrant.com>
parent: Tom Lane <tgl@sss.pgh.pa.us>
1 sibling, 0 replies; 33+ messages in thread
From: Andres Freund @ 2014-06-30 23:17 UTC (permalink / raw)
To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: Jeff Frost <jeff@pgexperts.com>; Matheus de Oliveira <matioli.matheus@gmail.com>; Soni M <diptatapa@gmail.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
On 2014-06-30 19:04:20 -0400, Tom Lane wrote:
> Jeff Frost <jeff@pgexperts.com> writes:
> >>> So it seems like we have a candidate explanation. I'm a bit surprised
> >>> that StandbyReleaseLocks would get this slow if there are only a dozen
> >>> AccessExclusiveLocks in place at any one time, though. Perhaps that
> >>> was a low point and there are often many more?
>
> > Since we turned on the monitoring for that, we had a peak of 13,550
> > AccessExclusiveLocks.
Any chance the workload also uses lots of subtransactions?
> Ah ... that's more like a number I can believe something would have
> trouble coping with. Did you see a noticeable slowdown with this?
> Now that we've seen that number, of course it's possible there was an
> even higher peak occurring when you saw the trouble.
>
> Perhaps there's an O(N^2) behavior in StandbyReleaseLocks, or maybe
> it just takes awhile to handle that many locks.
I don't think there's a O(n^2) in StandbyReleaseLocks() itself, but in
combination with StandbyReleaseLockTree() it looks possibly bad. The
latter will call StandbyReleaseLocks() for every xid/subxid, and each of
the StandbyReleaseLocks() will then trawl the entire RecoveryLockList...
It'd probably be better to implement ReleaseLocksTree() by sorting the
subxid list and bsearch that while iterating RecoveryLockList.
Greetings,
Andres Freund
--
Andres Freund http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services
--
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] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-06-30 23:57 Jeff Frost <jeff@pgexperts.com>
parent: Tom Lane <tgl@sss.pgh.pa.us>
1 sibling, 1 reply; 33+ messages in thread
From: Jeff Frost @ 2014-06-30 23:57 UTC (permalink / raw)
To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: Andres Freund <andres@2ndquadrant.com>; Matheus de Oliveira <matioli.matheus@gmail.com>; Soni M <diptatapa@gmail.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
On Jun 30, 2014, at 4:04 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Ah ... that's more like a number I can believe something would have
> trouble coping with. Did you see a noticeable slowdown with this?
> Now that we've seen that number, of course it's possible there was an
> even higher peak occurring when you saw the trouble.
>
> Perhaps there's an O(N^2) behavior in StandbyReleaseLocks, or maybe
> it just takes awhile to handle that many locks.
>
> Did you check whether the locks were all on temp tables of the
> ON COMMIT DROP persuasion?
Unfortunately not, because I went for a poor man's: SELECT count(*) FROM pg_locks WHERE mode = 'AccessExclusiveLock'
run in cron every minute.
That said, I'd bet it was mostly ON COMMIT DROP temp tables.
The unfortunate thing is I wouldn't know how to correlate that spike with the corresponding slowdown because the replica is about 5.5hrs lagged at the moment.
Hopefully it will get caught up tonight and we can see if there's a correlation tomorrow.=
^ permalink raw reply [nested|flat] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-07-01 17:12 Jeff Frost <jeff@pgexperts.com>
parent: Jeff Frost <jeff@pgexperts.com>
0 siblings, 1 reply; 33+ messages in thread
From: Jeff Frost @ 2014-07-01 17:12 UTC (permalink / raw)
To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: Andres Freund <andres@2ndquadrant.com>; Matheus de Oliveira <matioli.matheus@gmail.com>; Soni M <diptatapa@gmail.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
On Jun 30, 2014, at 4:57 PM, Jeff Frost <jeff@pgexperts.com> wrote:
>
> On Jun 30, 2014, at 4:04 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>
>> Ah ... that's more like a number I can believe something would have
>> trouble coping with. Did you see a noticeable slowdown with this?
>> Now that we've seen that number, of course it's possible there was an
>> even higher peak occurring when you saw the trouble.
>>
>> Perhaps there's an O(N^2) behavior in StandbyReleaseLocks, or maybe
>> it just takes awhile to handle that many locks.
>>
>> Did you check whether the locks were all on temp tables of the
>> ON COMMIT DROP persuasion?
>
>
> Unfortunately not, because I went for a poor man's: SELECT count(*) FROM pg_locks WHERE mode = 'AccessExclusiveLock'
> run in cron every minute.
>
> That said, I'd bet it was mostly ON COMMIT DROP temp tables.
>
> The unfortunate thing is I wouldn't know how to correlate that spike with the corresponding slowdown because the replica is about 5.5hrs lagged at the moment.
>
> Hopefully it will get caught up tonight and we can see if there's a correlation tomorrow.
And indeed it did catch up overnight and the lag increased shortly after a correlating spike in AccessExclusiveLocks that were generated by temp table creation with on commit drop.
^ permalink raw reply [nested|flat] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-07-01 19:20 Tom Lane <tgl@sss.pgh.pa.us>
parent: Jeff Frost <jeff@pgexperts.com>
0 siblings, 3 replies; 33+ messages in thread
From: Tom Lane @ 2014-07-01 19:20 UTC (permalink / raw)
To: Jeff Frost <jeff@pgexperts.com>; +Cc: Andres Freund <andres@2ndquadrant.com>; Matheus de Oliveira <matioli.matheus@gmail.com>; Soni M <diptatapa@gmail.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
Jeff Frost <jeff@pgexperts.com> writes:
>> On Jun 30, 2014, at 4:04 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>>> Did you check whether the locks were all on temp tables of the
>>> ON COMMIT DROP persuasion?
> And indeed it did catch up overnight and the lag increased shortly after a correlating spike in AccessExclusiveLocks that were generated by temp table creation with on commit drop.
OK, so we have a pretty clear idea of where the problem is now.
It seems like there are three, not mutually exclusive, ways we might
address this:
1. Local revisions inside StandbyReleaseLocks to make it perform better in
the presence of many locks. This would only be likely to improve matters
much if there's a fixable O(N^2) algorithmic issue; but there might well
be one.
2. Avoid WAL-logging AccessExclusiveLocks associated with temp tables, on
the grounds that no standby should be touching them. I'm not entirely
sure that that argument is bulletproof though; in particular, even though
a standby couldn't access the table's data, it's possible that it would be
interested in seeing consistent catalog entries.
3. Avoid WAL-logging AccessExclusiveLocks associated with
new-in-transaction tables, temp or not, on the grounds that no standby
could even see such tables until they're committed. We could go a bit
further and not take out any locks on a new-in-transaction table in the
first place, on the grounds that other transactions on the master can't
see 'em either.
It sounded like Andres had taken a preliminary look at #1 and found a
possible avenue for improvement, which I'd encourage him to pursue.
For both #2 and the conservative version of #3, the main implementation
problem would be whether the lock WAL-logging code has cheap access to
the necessary information. I suspect it doesn't.
The radical version of #3 might be pretty easy to do, at least to the
extent of removing locks taken out during CREATE TABLE. I suspect there
are some assertions or other consistency checks that would get unhappy if
we manipulate relations without locks, though, so those would have to be
taught about the exception. Also, we sometimes forget new-in-transaction
status during relcache flush events; it's not clear if that would be a
problem for this.
I don't plan to work on this myself, but perhaps someone with more
motivation will want to run with these ideas.
regards, tom lane
--
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] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-07-02 19:01 Andres Freund <andres@2ndquadrant.com>
parent: Tom Lane <tgl@sss.pgh.pa.us>
2 siblings, 1 reply; 33+ messages in thread
From: Andres Freund @ 2014-07-02 19:01 UTC (permalink / raw)
To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: Jeff Frost <jeff@pgexperts.com>; Matheus de Oliveira <matioli.matheus@gmail.com>; Soni M <diptatapa@gmail.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
On 2014-07-01 15:20:37 -0400, Tom Lane wrote:
> Jeff Frost <jeff@pgexperts.com> writes:
> >> On Jun 30, 2014, at 4:04 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> >>> Did you check whether the locks were all on temp tables of the
> >>> ON COMMIT DROP persuasion?
>
> > And indeed it did catch up overnight and the lag increased shortly after a correlating spike in AccessExclusiveLocks that were generated by temp table creation with on commit drop.
>
> OK, so we have a pretty clear idea of where the problem is now.
>
> It seems like there are three, not mutually exclusive, ways we might
> address this:
>
> 1. Local revisions inside StandbyReleaseLocks to make it perform better in
> the presence of many locks. This would only be likely to improve matters
> much if there's a fixable O(N^2) algorithmic issue; but there might well
> be one.
>
> It sounded like Andres had taken a preliminary look at #1 and found a
> possible avenue for improvement, which I'd encourage him to pursue.
>
I don't have the resources to do this right now, but yes, I think we can
get relatively easily get rid of the O(num_locks * num_subtransactions)
behaviour.
> 2. Avoid WAL-logging AccessExclusiveLocks associated with temp tables, on
> the grounds that no standby should be touching them. I'm not entirely
> sure that that argument is bulletproof though; in particular, even though
> a standby couldn't access the table's data, it's possible that it would be
> interested in seeing consistent catalog entries.
Hm. We definitely perform checks surprisingly late for those. It's
possible to do SELECT * FROM pg_temp_<nn>.whatever; without an error f
there's no rows of if the rest of the plan doesn't do accesses to that
table. The check prohibiting access is only in bufmgr.c...
So yea, I don't think we can do this for at least < 9.4. And there
it'll still be hard.
> 3. Avoid WAL-logging AccessExclusiveLocks associated with
> new-in-transaction tables, temp or not, on the grounds that no standby
> could even see such tables until they're committed. We could go a bit
> further and not take out any locks on a new-in-transaction table in the
> first place, on the grounds that other transactions on the master can't
> see 'em either.
>
> For both #2 and the conservative version of #3, the main implementation
> problem would be whether the lock WAL-logging code has cheap access to
> the necessary information. I suspect it doesn't.
Not trivially. It's logged directly in LockAcquireExtended(). We could
add the information into locktags as there's unused fields for relation
locktags, but brrr.
> The radical version of #3 might be pretty easy to do, at least to the
> extent of removing locks taken out during CREATE TABLE. I suspect there
> are some assertions or other consistency checks that would get unhappy if
> we manipulate relations without locks, though, so those would have to be
> taught about the exception.
>
> Also, we sometimes forget new-in-transaction
> status during relcache flush events; it's not clear if that would be a
> problem for this.
I think that hole is actually pluggable in newer releases - at least
there's no code around that assumes rd_createSubid now is persistent,
even across cache resets.
But I think more importantly it's probably quite possible to hit a
similar problem without ON COMMIT DROP relations. Say DISCARD TEMP
inside a transaction (with several subxacts) or so? So we probaly really
should fix the bad scaling.
Greetings,
Andres Freund
--
Andres Freund http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services
--
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] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-07-02 19:14 Tom Lane <tgl@sss.pgh.pa.us>
parent: Andres Freund <andres@2ndquadrant.com>
0 siblings, 0 replies; 33+ messages in thread
From: Tom Lane @ 2014-07-02 19:14 UTC (permalink / raw)
To: Andres Freund <andres@2ndquadrant.com>; +Cc: Jeff Frost <jeff@pgexperts.com>; Matheus de Oliveira <matioli.matheus@gmail.com>; Soni M <diptatapa@gmail.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
Andres Freund <andres@2ndquadrant.com> writes:
> On 2014-07-01 15:20:37 -0400, Tom Lane wrote:
>> It seems like there are three, not mutually exclusive, ways we might
>> address this:
> But I think more importantly it's probably quite possible to hit a
> similar problem without ON COMMIT DROP relations. Say DISCARD TEMP
> inside a transaction (with several subxacts) or so? So we probaly really
> should fix the bad scaling.
Well, my thought was that these approaches would address somewhat
different sets of use-cases, and we might well want to do more than one.
Even if StandbyReleaseLocks were zero-cost, not emitting the WAL in the
first place is surely considerably cheaper yet.
regards, tom lane
--
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] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-07-03 09:34 Simon Riggs <simon@2ndQuadrant.com>
parent: Tom Lane <tgl@sss.pgh.pa.us>
2 siblings, 0 replies; 33+ messages in thread
From: Simon Riggs @ 2014-07-03 09:34 UTC (permalink / raw)
To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: Jeff Frost <jeff@pgexperts.com>; Andres Freund <andres@2ndquadrant.com>; Matheus de Oliveira <matioli.matheus@gmail.com>; Soni M <diptatapa@gmail.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
On 1 July 2014 20:20, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> I don't plan to work on this myself, but perhaps someone with more
> motivation will want to run with these ideas.
I was planning to work on improving performance of replication apply
over the summer, mid July - Aug, so I'll add this to the list.
--
Simon Riggs http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services
--
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] 33+ messages in thread
* Re: Postgres Replaying WAL slowly
@ 2014-09-17 17:15 Simon Riggs <simon@2ndquadrant.com>
parent: Tom Lane <tgl@sss.pgh.pa.us>
2 siblings, 0 replies; 33+ messages in thread
From: Simon Riggs @ 2014-09-17 17:15 UTC (permalink / raw)
To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: Jeff Frost <jeff@pgexperts.com>; Andres Freund <andres@2ndquadrant.com>; Matheus de Oliveira <matioli.matheus@gmail.com>; Soni M <diptatapa@gmail.com>; Heikki Linnakangas <hlinnakangas@vmware.com>; pgsql-performance
On 1 July 2014 20:20, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Jeff Frost <jeff@pgexperts.com> writes:
>>> On Jun 30, 2014, at 4:04 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>>>> Did you check whether the locks were all on temp tables of the
>>>> ON COMMIT DROP persuasion?
>
>> And indeed it did catch up overnight and the lag increased shortly after a correlating spike in AccessExclusiveLocks that were generated by temp table creation with on commit drop.
>
> OK, so we have a pretty clear idea of where the problem is now.
>
> It seems like there are three, not mutually exclusive, ways we might
> address this:
>
> 1. Local revisions inside StandbyReleaseLocks to make it perform better in
> the presence of many locks. This would only be likely to improve matters
> much if there's a fixable O(N^2) algorithmic issue; but there might well
> be one.
>
> 2. Avoid WAL-logging AccessExclusiveLocks associated with temp tables, on
> the grounds that no standby should be touching them. I'm not entirely
> sure that that argument is bulletproof though; in particular, even though
> a standby couldn't access the table's data, it's possible that it would be
> interested in seeing consistent catalog entries.
>
> 3. Avoid WAL-logging AccessExclusiveLocks associated with
> new-in-transaction tables, temp or not, on the grounds that no standby
> could even see such tables until they're committed. We could go a bit
> further and not take out any locks on a new-in-transaction table in the
> first place, on the grounds that other transactions on the master can't
> see 'em either.
>
> It sounded like Andres had taken a preliminary look at #1 and found a
> possible avenue for improvement, which I'd encourage him to pursue.
>
> For both #2 and the conservative version of #3, the main implementation
> problem would be whether the lock WAL-logging code has cheap access to
> the necessary information. I suspect it doesn't.
>
> The radical version of #3 might be pretty easy to do, at least to the
> extent of removing locks taken out during CREATE TABLE. I suspect there
> are some assertions or other consistency checks that would get unhappy if
> we manipulate relations without locks, though, so those would have to be
> taught about the exception. Also, we sometimes forget new-in-transaction
> status during relcache flush events; it's not clear if that would be a
> problem for this.
>
> I don't plan to work on this myself, but perhaps someone with more
> motivation will want to run with these ideas.
Patch implements option 2 in the above.
Skipping the locks entirely seems like it opens a can of worms.
Skipping the lock for temp tables is valid since locks don't need to
exist on the standby. Any catalog entries for them will exist, but the
rows will show them as temp and nobody would expect them to be valid
outside of the original session.
Patch implements a special case that takes the lock normally, but
skips WAL logging the lock info.
--
Simon Riggs http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services
--
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
Attachments:
temp_tables_skip_logging_locks.v1.patch (application/octet-stream, 8.2K) download
diff --git a/src/backend/access/heap/heapam.c b/src/backend/access/heap/heapam.c
index ae15c0b..cda51cc 100644
--- a/src/backend/access/heap/heapam.c
+++ b/src/backend/access/heap/heapam.c
@@ -1014,6 +1014,8 @@ fastgetattr(HeapTuple tup, int attnum, TupleDesc tupleDesc,
*
* NB: a "relation" is anything with a pg_class entry. The caller is
* expected to check whether the relkind is something it can handle.
+ *
+ * relation_open_temp() is a special case that avoids logging locks.
* ----------------
*/
Relation
@@ -1042,6 +1044,31 @@ relation_open(Oid relationId, LOCKMODE lockmode)
return r;
}
+Relation
+relation_open_temp(Oid relationId, LOCKMODE lockmode)
+{
+ Relation r;
+
+ Assert(lockmode >= NoLock && lockmode < MAX_LOCKMODES);
+
+ /* Get the lock before trying to open the relcache entry */
+ if (lockmode != NoLock)
+ LockRelationOidTemp(relationId, lockmode);
+
+ /* The relcache does all the real work... */
+ r = RelationIdGetRelation(relationId);
+
+ if (!RelationIsValid(r))
+ elog(ERROR, "could not open relation with OID %u", relationId);
+
+ /* Make note that we've accessed a temporary relation */
+ MyXactAccessedTempRel = true;
+
+ pgstat_initstats(r);
+
+ return r;
+}
+
/* ----------------
* try_relation_open - open any relation by relation OID
*
diff --git a/src/backend/commands/tablecmds.c b/src/backend/commands/tablecmds.c
index 7bc579b..f525a47 100644
--- a/src/backend/commands/tablecmds.c
+++ b/src/backend/commands/tablecmds.c
@@ -669,8 +669,13 @@ DefineRelation(CreateStmt *stmt, char relkind, Oid ownerId)
* really necessary for locking out other backends (since they can't see
* the new rel anyway until we commit), but it keeps the lock manager from
* complaining about deadlock risks.
+ *
+ * Temp tables follow a special case here to avoid logging locks.
*/
- rel = relation_open(relationId, AccessExclusiveLock);
+ if (stmt->relation->relpersistence == RELPERSISTENCE_TEMP)
+ rel = relation_open_temp(relationId, AccessExclusiveLock);
+ else
+ rel = relation_open(relationId, AccessExclusiveLock);
/*
* Now add any newly specified column default values and CHECK constraints
diff --git a/src/backend/storage/ipc/standby.c b/src/backend/storage/ipc/standby.c
index 1c327fd..2ed545a 100644
--- a/src/backend/storage/ipc/standby.c
+++ b/src/backend/storage/ipc/standby.c
@@ -365,7 +365,7 @@ ResolveRecoveryConflictWithLock(Oid dbOid, Oid relOid)
ResolveRecoveryConflictWithVirtualXIDs(backends,
PROCSIG_RECOVERY_CONFLICT_LOCK);
- if (LockAcquireExtended(&locktag, AccessExclusiveLock, true, true, false)
+ if (LockAcquireExtended(&locktag, AccessExclusiveLock, true, true, false, false)
!= LOCKACQUIRE_NOT_AVAIL)
lock_acquired = true;
}
@@ -591,7 +591,7 @@ StandbyAcquireAccessExclusiveLock(TransactionId xid, Oid dbOid, Oid relOid)
*/
SET_LOCKTAG_RELATION(locktag, newlock->dbOid, newlock->relOid);
- if (LockAcquireExtended(&locktag, AccessExclusiveLock, true, true, false)
+ if (LockAcquireExtended(&locktag, AccessExclusiveLock, true, true, false, false)
== LOCKACQUIRE_NOT_AVAIL)
ResolveRecoveryConflictWithLock(newlock->dbOid, newlock->relOid);
}
diff --git a/src/backend/storage/lmgr/lmgr.c b/src/backend/storage/lmgr/lmgr.c
index 6cc4d26..747f0ac 100644
--- a/src/backend/storage/lmgr/lmgr.c
+++ b/src/backend/storage/lmgr/lmgr.c
@@ -82,6 +82,7 @@ SetLocktagRelationOid(LOCKTAG *tag, Oid relid)
*
* Lock a relation given only its OID. This should generally be used
* before attempting to open the relation's relcache entry.
+ * Any changes here should also change LockRelationOidTemp below.
*/
void
LockRelationOid(Oid relid, LOCKMODE lockmode)
@@ -108,6 +109,38 @@ LockRelationOid(Oid relid, LOCKMODE lockmode)
}
/*
+ * LockRelationOidTemp
+ *
+ * Lock a relation given only its OID. This should generally be used
+ * before attempting to open the relation's relcache entry.
+ *
+ * Special case version of LockRelationOid that avoids logging locks.
+ */
+void
+LockRelationOidTemp(Oid relid, LOCKMODE lockmode)
+{
+ LOCKTAG tag;
+ LockAcquireResult res;
+
+ SetLocktagRelationOid(&tag, relid);
+
+ res = LockAcquireExtended(&tag, lockmode, false, false, true, false);
+
+ /*
+ * Now that we have the lock, check for invalidation messages, so that we
+ * will update or flush any stale relcache entry before we try to use it.
+ * RangeVarGetRelid() specifically relies on us for this. We can skip
+ * this in the not-uncommon case that we already had the same type of lock
+ * being requested, since then no one else could have modified the
+ * relcache entry in an undesirable way. (In the case where our own xact
+ * modifies the rel, the relcache update happens via
+ * CommandCounterIncrement, not here.)
+ */
+ if (res != LOCKACQUIRE_ALREADY_HELD)
+ AcceptInvalidationMessages();
+}
+
+/*
* ConditionalLockRelationOid
*
* As above, but only lock if we can get the lock without blocking.
diff --git a/src/backend/storage/lmgr/lock.c b/src/backend/storage/lmgr/lock.c
index 723051e..e281870 100644
--- a/src/backend/storage/lmgr/lock.c
+++ b/src/backend/storage/lmgr/lock.c
@@ -674,7 +674,7 @@ LockAcquire(const LOCKTAG *locktag,
bool sessionLock,
bool dontWait)
{
- return LockAcquireExtended(locktag, lockmode, sessionLock, dontWait, true);
+ return LockAcquireExtended(locktag, lockmode, sessionLock, dontWait, true, true);
}
/*
@@ -691,7 +691,8 @@ LockAcquireExtended(const LOCKTAG *locktag,
LOCKMODE lockmode,
bool sessionLock,
bool dontWait,
- bool reportMemoryError)
+ bool reportMemoryError,
+ bool log_lock)
{
LOCKMETHODID lockmethodid = locktag->locktag_lockmethodid;
LockMethod lockMethodTable;
@@ -704,7 +705,7 @@ LockAcquireExtended(const LOCKTAG *locktag,
uint32 hashcode;
LWLock *partitionLock;
int status;
- bool log_lock = false;
+ bool lock_logged = false;
if (lockmethodid <= 0 || lockmethodid >= lengthof(LockMethods))
elog(ERROR, "unrecognized lock method: %d", lockmethodid);
@@ -801,11 +802,11 @@ LockAcquireExtended(const LOCKTAG *locktag,
*/
if (lockmode >= AccessExclusiveLock &&
locktag->locktag_type == LOCKTAG_RELATION &&
- !RecoveryInProgress() &&
+ log_lock &&
XLogStandbyInfoActive())
{
LogAccessExclusiveLockPrepare();
- log_lock = true;
+ lock_logged = true;
}
/*
@@ -1028,7 +1029,7 @@ LockAcquireExtended(const LOCKTAG *locktag,
* Emit a WAL record if acquisition of this lock needs to be replayed in a
* standby server.
*/
- if (log_lock)
+ if (lock_logged)
{
/*
* Decode the locktag back to the original values, to avoid sending
diff --git a/src/include/access/heapam.h b/src/include/access/heapam.h
index 493839f..97b3502 100644
--- a/src/include/access/heapam.h
+++ b/src/include/access/heapam.h
@@ -81,6 +81,7 @@ typedef struct HeapUpdateFailureData
/* in heap/heapam.c */
extern Relation relation_open(Oid relationId, LOCKMODE lockmode);
+extern Relation relation_open_temp(Oid relationId, LOCKMODE lockmode);
extern Relation try_relation_open(Oid relationId, LOCKMODE lockmode);
extern Relation relation_openrv(const RangeVar *relation, LOCKMODE lockmode);
extern Relation relation_openrv_extended(const RangeVar *relation,
diff --git a/src/include/storage/lmgr.h b/src/include/storage/lmgr.h
index e9447b7..52bcbe1 100644
--- a/src/include/storage/lmgr.h
+++ b/src/include/storage/lmgr.h
@@ -38,6 +38,7 @@ extern void RelationInitLockInfo(Relation relation);
/* Lock a relation */
extern void LockRelationOid(Oid relid, LOCKMODE lockmode);
+extern void LockRelationOidTemp(Oid relid, LOCKMODE lockmode);
extern bool ConditionalLockRelationOid(Oid relid, LOCKMODE lockmode);
extern void UnlockRelationId(LockRelId *relid, LOCKMODE lockmode);
extern void UnlockRelationOid(Oid relid, LOCKMODE lockmode);
diff --git a/src/include/storage/lock.h b/src/include/storage/lock.h
index 4c49e3c..75e7797 100644
--- a/src/include/storage/lock.h
+++ b/src/include/storage/lock.h
@@ -503,7 +503,8 @@ extern LockAcquireResult LockAcquireExtended(const LOCKTAG *locktag,
LOCKMODE lockmode,
bool sessionLock,
bool dontWait,
- bool report_memory_error);
+ bool report_memory_error,
+ bool log_lock);
extern void AbortStrongLockAcquire(void);
extern bool LockRelease(const LOCKTAG *locktag,
LOCKMODE lockmode, bool sessionLock);
end of thread, other threads:[~2014-09-17 17:15 UTC | newest]
Thread overview: 33+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2014-06-29 08:14 Postgres Replaying WAL slowly Soni M <diptatapa@gmail.com>
2014-06-29 08:31 ` Heikki Linnakangas <hlinnakangas@vmware.com>
2014-06-29 12:43 ` Soni M <diptatapa@gmail.com>
2014-06-29 13:05 ` Soni M <diptatapa@gmail.com>
2014-06-30 07:05 ` Heikki Linnakangas <hlinnakangas@vmware.com>
2014-06-30 14:46 ` Soni M <diptatapa@gmail.com>
2014-06-30 16:14 ` Heikki Linnakangas <hlinnakangas@vmware.com>
2014-06-30 17:04 ` Jeff Frost <jeff@pgexperts.com>
2014-06-30 17:14 ` Andres Freund <andres@2ndquadrant.com>
2014-06-30 17:29 ` Soni M <diptatapa@gmail.com>
2014-06-30 18:34 ` Jeff Frost <jeff@pgexperts.com>
2014-06-30 18:39 ` Andres Freund <andres@2ndquadrant.com>
2014-06-30 19:17 ` Jeff Frost <jeff@pgexperts.com>
2014-06-30 19:25 ` Jeff Frost <jeff@pgexperts.com>
2014-06-30 19:32 ` Tom Lane <tgl@sss.pgh.pa.us>
2014-06-30 19:42 ` Jeff Frost <jeff@pgexperts.com>
2014-06-30 19:54 ` Matheus de Oliveira <matioli.matheus@gmail.com>
2014-06-30 19:57 ` Jeff Frost <jeff@pgexperts.com>
2014-06-30 20:15 ` Andres Freund <andres@2ndquadrant.com>
2014-06-30 20:21 ` Jeff Frost <jeff@pgexperts.com>
2014-06-30 20:39 ` Tom Lane <tgl@sss.pgh.pa.us>
2014-06-30 20:46 ` Jeff Frost <jeff@pgexperts.com>
2014-06-30 21:52 ` Jeff Frost <jeff@pgexperts.com>
2014-06-30 23:04 ` Tom Lane <tgl@sss.pgh.pa.us>
2014-06-30 23:17 ` Andres Freund <andres@2ndquadrant.com>
2014-06-30 23:57 ` Jeff Frost <jeff@pgexperts.com>
2014-07-01 17:12 ` Jeff Frost <jeff@pgexperts.com>
2014-07-01 19:20 ` Tom Lane <tgl@sss.pgh.pa.us>
2014-07-02 19:01 ` Andres Freund <andres@2ndquadrant.com>
2014-07-02 19:14 ` Tom Lane <tgl@sss.pgh.pa.us>
2014-07-03 09:34 ` Simon Riggs <simon@2ndQuadrant.com>
2014-09-17 17:15 ` Simon Riggs <simon@2ndquadrant.com>
2014-06-30 18:40 ` Pavel Stehule <pavel.stehule@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