0

have a strange trouble with getting new rows on replica on PostgreSQL on AWS. I have master database on AWS with constant flow inserts/updates not with big rate. And these changes are replicated through WAL streaming to replica db. When i do query on replica to get new fresh rows written to master all works fine. When i do long read query on this replica, i stop getting new data in other transactions to same replica, though i still can get data before long scan transaction started.

I tried to look at locks and pg_activity table and could not get any meaningful information about appeared locks. From knowhelege i have, to lock some rows PG have to lock resource in AccessExclusive mode. Locks i see in table which made by long query on replica all are in AccessShare mode and no other exlusive locks are there. From my perspective, this looks like that when i do long query on replica new rows imported by WAL parsing are getting locked for reading.

What other ways or tools can i use to understand problem and find the cause?

https://docs.aws.amazon.com/AmazonRDS/latest/UserGuide/USER_PostgreSQL.Replication.ReadReplicas.html#USER_PostgreSQL.Replication.ReadReplicas.Configuration

Here are commands and text description i used for debug:

  1. Trying to query replica locks without any long running queries:
SELECT lock.locktype,
       lock.relation::regclass,
       lock.mode,
       lock.transactionid AS tid,
       lock.virtualtransaction AS vtid,
       lock.pid,
       lock.granted
FROM pg_catalog.pg_locks LOCK
LEFT JOIN pg_catalog.pg_database db ON db.oid = lock.database
WHERE (db.datname = 'DB'
       OR db.datname IS NULL)
  AND NOT lock.pid = pg_backend_pid()
ORDER BY lock.pid;

  locktype  | relation |     mode      | tid | vtid | pid | granted
------------+----------+---------------+-----+------+-----+---------
 virtualxid |          | ExclusiveLock |     | 1/0  | 352 | t
(1 row)

geting only virtualxid of select locks query
  1. Running long scan/index scan query and looking for locks, activity table:

run long query:

SELECT id,
       created_at
FROM tbl
ORDER BY created_at DESC
LIMIT 10000000;

after that any short query like below stops giving new rows updated on master and replicated to replica where all queries are executed:

SELECT id,
       created_at
FROM tbl
ORDER BY created_at DESC
LIMIT 10;

trying to find locking reason:

SELECT lock.locktype,
       lock.relation::regclass,
       lock.mode,
       lock.transactionid AS tid,
       lock.virtualtransaction AS vtid,
       lock.pid,
       lock.granted
FROM pg_catalog.pg_locks LOCK
LEFT JOIN pg_catalog.pg_database db ON db.oid = lock.database
WHERE (db.datname = 'DB'
       OR db.datname IS NULL)
  AND NOT lock.pid = pg_backend_pid()
ORDER BY lock.pid;

  locktype  |                      relation                      |      mode       | tid |   vtid    |  pid  | granted
------------+----------------------------------------------------+-----------------+-----+-----------+-------+---------
 virtualxid |                                                    | ExclusiveLock   |     | 1/0       |   352 | t
 relation   | "IX_tbl_001"                                       | AccessShareLock |     | 5/1231551 | 24973 | t
 relation   | "IX_tbl_002"                                       | AccessShareLock |     | 5/1231551 | 24973 | t
 relation   | "IX_tbl_003"                                       | AccessShareLock |     | 5/1231551 | 24973 | t
 relation   | "IX_tbl_004"                                       | AccessShareLock |     | 5/1231551 | 24973 | t
 relation   | "IX_tbl_005"                                       | AccessShareLock |     | 5/1231551 | 24973 | t
 relation   | "IX_tbl_005"                                       | AccessShareLock |     | 5/1231551 | 24973 | t
 relation   | "IX_tbl_007"                                       | AccessShareLock |     | 5/1231551 | 24973 | t
 relation   | "IX_tbl_008"                                       | AccessShareLock |     | 5/1231551 | 24973 | t
 relation   | "IX_tbl_009"                                       | AccessShareLock |     | 5/1231551 | 24973 | t
 relation   | "IX_tbl_010"                                       | AccessShareLock |     | 5/1231551 | 24973 | t
 relation   | "IX_tbl_011"                                       | AccessShareLock |     | 5/1231551 | 24973 | t
 relation   | "IX_tbl_012"                                       | AccessShareLock |     | 5/1231551 | 24973 | t
 relation   | "IX_tbl_013"                                       | AccessShareLock |     | 5/1231551 | 24973 | t
 relation   | "PK_tbl"                                           | AccessShareLock |     | 5/1231551 | 24973 | t
 relation   | "tbl"                                              | AccessShareLock |     | 5/1231551 | 24973 | t
 virtualxid |                                                    | ExclusiveLock   |     | 5/1231551 | 24973 | t
 relation   | "IX_tbl_014"                                       | AccessShareLock |     | 5/1231551 | 24973 | t
 relation   | "IX_tbl_015"                                       | AccessShareLock |     | 5/1231551 | 24973 | t
 relation   | "IX_tbl_016"                                       | AccessShareLock |     | 5/1231551 | 24973 | t
 relation   | "IX_tbl_017"                                       | AccessShareLock |     | 5/1231551 | 24973 | t
 relation   | "IX_tbl_018"                                       | AccessShareLock |     | 5/1231551 | 24973 | t
SELECT
    pid,
    backend_start,
    query_start,
    state_change,
    wait_event_type,
    wait_event,
    query,
    backend_type
FROM
    pg_stat_activity;


-[ RECORD 1 ]---+---------------------------------------------------------------------------
pid             | 461
backend_start   | 2023-03-04 07:17:45.420192+00
query_start     | 2023-03-05 14:48:19.722021+00
state_change    | 2023-03-05 14:48:19.722038+00
wait_event_type | Client
wait_event      | ClientRead
query           | SELECT 1
backend_type    | client backend
-[ RECORD 2 ]---+---------------------------------------------------------------------------
pid             | 28583
backend_start   | 2023-03-04 14:29:51.138626+00
query_start     | 2023-03-05 14:48:21.916923+00
state_change    | 2023-03-05 14:48:21.916971+00
wait_event_type | Client
wait_event      | ClientRead
query           | COMMIT
backend_type    | client backend
-[ RECORD 3 ]---+---------------------------------------------------------------------------
pid             | 28584
backend_start   | 2023-03-04 14:29:52.091085+00
query_start     | 2023-03-05 14:47:52.314253+00
state_change    | 2023-03-05 14:47:52.314281+00
wait_event_type | Client
wait_event      | ClientRead
query           | ROLLBACK
backend_type    | client backend
-[ RECORD 4 ]---+---------------------------------------------------------------------------
pid             | 22783
backend_start   | 2023-03-05 14:31:10.44282+00
query_start     | 2023-03-05 14:48:22.722693+00
state_change    | 2023-03-05 14:48:22.722695+00
wait_event_type |
wait_event      |
query           | SELECT                                                                    +
                |     pid,                                                                  +
                |     backend_start,                                                        +
                |     query_start,                                                          +
                |     state_change,                                                         +
                |     wait_event_type,                                                      +
                |     wait_event,                                                           +
                |     query,                                                                +
                |     backend_type                                                          +
                | FROM pg_stat_activity;
backend_type    | client backend
-[ RECORD 5 ]---+---------------------------------------------------------------------------
pid             | 23849
backend_start   | 2023-03-05 14:47:55.602716+00
query_start     | 2023-03-05 14:48:11.454558+00
state_change    | 2023-03-05 14:48:11.454561+00
wait_event_type | Client
wait_event      | ClientWrite
query           | select id, created_at from tbl order by created_at desc limit 10000000;
backend_type    | client backend
[ RECORD 6 ]---+---------------------------------------------------------------------------
pid             | 373
backend_start   | 2023-03-04 07:17:44.493326+00
query_start     |
state_change    |
wait_event_type | Activity
wait_event      | RecoveryWalStream
query           |
backend_type    | startup
-[ RECORD 7 ]---+---------------------------------------------------------------------------
pid             | 383
backend_start   | 2023-03-04 07:17:44.612868+00
query_start     |
state_change    |
wait_event_type | Activity
wait_event      | BgWriterHibernate
query           |
backend_type    | background writer
-[ RECORD 8 ]---+---------------------------------------------------------------------------
pid             | 382
backend_start   | 2023-03-04 07:17:44.613552+00
query_start     |
state_change    |
wait_event_type | Activity
wait_event      | CheckpointerMain
query           |
backend_type    | checkpointer
-[ RECORD 9 ]---+---------------------------------------------------------------------------
pid             | 1065
backend_start   | 2023-03-04 07:18:49.420368+00
query_start     |
state_change    |
wait_event_type | Activity
wait_event      | WalReceiverMain
query           |
backend_type    | walreceiver

Postgres config:

here i compare settings of local PG where all works well (first value) and replica (second value)

'archive_mode': ('off', 'on'),
'archive_timeout': ('0', '300'),
'autovacuum_analyze_scale_factor': ('0.1', '0.05'),
'autovacuum_naptime': ('60', '15'),
'autovacuum_vacuum_cost_limit': ('-1', '200'),
'autovacuum_vacuum_scale_factor': ('0.2', '0.1'),
'checkpoint_completion_target': ('0.5', '0.9'),
'data_checksums': ('off', 'on'),
'effective_cache_size': ('524288', '486132'),
'huge_pages': ('try', 'on'),
'idle_in_transaction_session_timeout': ('0', '86400000'),
'jit': ('on', 'off'),
'listen_addresses': ('localhost', '*'),
'log_autovacuum_min_duration': ('-1', '10000'),
'log_checkpoints': ('off', 'on'),
'log_file_mode': ('0600', '0644'),
'log_rotation_age': ('1440', '60'),
'logging_collector': ('off', 'on'),
'maintenance_work_mem': ('65536', '127510'),
'max_connections': ('100', '5000'),
'max_replication_slots': ('10', '20'),
'max_stack_depth': ('2048', '6144'),
'max_standby_archive_delay': ('30000', '100000'),
'max_standby_streaming_delay': ('30000', '60000'),
'max_wal_senders': ('10', '20'),
'max_wal_size': ('1024', '2048'),
'max_worker_processes': ('8', '32'),
'min_wal_size': ('80', '192'),
'pg_stat_statements.max': ('', '5000'),
'pg_stat_statements.save': ('', 'on'),
'pg_stat_statements.track': ('', 'top'),
'pg_stat_statements.track_planning': ('', 'off'),
'pg_stat_statements.track_utility': ('', 'on'),
'server_version_num': ('130009', '130007'),
'shared_buffers': ('16384', '243066'),
'tcp_keepalives_count': ('9', '2'),
'tcp_keepalives_idle': ('7200', '300'),
'tcp_keepalives_interval': ('75', '30'),
'track_activity_query_size': ('1024', '4096'),
'track_functions': ('none', 'pl'),
'track_io_timing': ('off', 'on'),
'transaction_read_only': ('off', 'on'),
'unix_socket_permissions': ('0777', '0700'),
'vacuum_cost_page_miss': ('10', '5'),
'wal_buffers': ('512', '7595'),
'wal_compression': ('off', 'on'),
'wal_keep_size': ('0', '2048'),
'wal_receiver_timeout': ('60000', '30000'),
'wal_segment_size': ('16777216', '67108864'),
'wal_sender_timeout': ('60000', '30000')

Update:

tried to check views pg_stat_database_conflicts and pg_stat_replication.

from pg_stat_database_conflicts I see that there are "confl_snapshot" conflicts. According to the article, the most likely reason for it is "Snapshot replication conflicts". There is also a topic on recovery conflicts.

As I got from this topic and the article, I can eliminate from replica queries cancelling by tuning hot_standby_feedback parameter, thus making the master keep data used by the query on standby. And if this query never ends dead tuples on master will never be deleted.

Also, in my queries i did not see any replay_lsn lags, but saw confl_snapshots conflicts:

DB=> select * from pg_stat_database_conflicts where datname='DB';
-[ RECORD 1 ]----+--------
datid            | 16416
datname          | DB
confl_tablespace | 0
confl_lock       | 0
confl_snapshot   | 4
confl_bufferpin  | 0
confl_deadlock   | 0


DB=> select * from pg_stat_replication;
-[ RECORD 1 ]----+-------------
pid              | 399
usesysid         | 16396
usename          | rdsrepladmin
application_name | walreceiver
client_addr      |
client_hostname  |
client_port      |
backend_start    |
backend_xmin     |
state            |
sent_lsn         |
write_lsn        |
flush_lsn        |
replay_lsn       |
write_lag        |
flush_lag        |
replay_lag       |
sync_priority    |
sync_state       |
reply_time       |
-[ RECORD 2 ]----+-------------
pid              | 398
usesysid         | 16396
usename          | rdsrepladmin
application_name | walreceiver
client_addr      |
client_hostname  |
client_port      |
backend_start    |
backend_xmin     |
state            |
sent_lsn         |
write_lsn        |
flush_lsn        |
replay_lsn       |
write_lag        |
flush_lag        |
replay_lag       |
sync_priority    |
sync_state       |
reply_time       |

1 Answer 1

0

There are no locks; this is probably only a replication conflict. If you look at pg_stat_replication on the primary side, you should see that replay_lsn starts lagging when changes are no longer replayed on the standby. You can prevent that by reducing max_standby_streaming_delay on the standby, but only at the price of having queries on the standby canceled.

3
  • Question still unclear to me if i can get fresh data on standby turning hot_standby_feedback on and setting max_standby_delay to some small value. Logic says that if we tell master to keep the WAL version compliant to standby`s WAL during queries last, standby may apply got WAL without conflicts caused by VACUUM. These are my untested thoughts at the moment.
    – SkyGame
    Mar 7, 2023 at 16:20
  • It should get rid of snapshot conflicts. But there are others. Mar 7, 2023 at 16:25
  • so it is for everyone to decide what steps to take, use another source of data, replicas with different max_standby_delay settings or face other conflicts. Me personally cheerful to get help from community, thanks!
    – SkyGame
    Mar 12, 2023 at 13:34

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.