On 2017-03-09 11:06, Erik Rijkers wrote:
On 2017-03-08 10:36, Petr Jelinek wrote:
On 07/03/17 23:30, Erik Rijkers wrote:
On 2017-03-06 11:27, Petr Jelinek wrote:
0001-Reserve-global-xmin-for-create-slot-snasphot-export.patch +
0002-Don-t-use-on-disk-snapshots-for-snapshot-export-in-l.patch+
0003-Prevent-snapshot-builder-xmin-from-going-backwards.patch +
0004-Fix-xl_running_xacts-usage-in-snapshot-builder.patch +
0005-Skip-unnecessary-snapshot-builds.patch +
0001-Logical-replication-support-for-initial-data-copy-v6.patch
The attached bz2 contains
- an output file from pgbench_derail2.sh (also attached, as it changes
somewhat all the time); the
- the pg_waldump output from both master (file with .1. in it) and
replica (.2.).
- the 2 logfiles.
I forgot to include the bash-output file. Now attached. This file
should have been in the bz2 I sent a few minutes ago.
========= iteration 1 -- 1 of 10 =========
============================================================================
-- scale 25 clients 64 duration 300 CLEAN_ONLY=
============================================================================
-- hostname: barzoi
-- timestamp: 20170309_1021
-- master_start_time 2017-03-08 12:04:02.127127+01 replica_start_time
2017-03-08 12:04:02.12713+01
-- master patch-md5 [59c92165d4a328d68450ef0e922c0a42]
-- replica patch-md5 [59c92165d4a328d68450ef0e922c0a42] (ok)
-- synchronous_commit, master [on] replica [off]
-- master_assert [on] replica_assert [on]
-- self md5 87554cfed7cda67ad292b6481e1b8b41 ./pgbench_derail2.sh
clean-at-start-call
creating tables...
1699900 of 2500000 tuples (67%) done (elapsed 5.19 s, remaining 2.44 s)
2500000 of 2500000 tuples (100%) done (elapsed 7.51 s, remaining 0.00 s)
vacuum...
set primary keys...
done.
create publication pub1 for all tables;
create subscription sub1 connection 'port=6972' publication pub1 with
(disabled);
alter subscription sub1 enable;
-- pgbench -c 64 -j 8 -T 300 -P 60 -n -- scale 25
progress: 60.0 s, 134.4 tps, lat 472.280 ms stddev 622.992
progress: 120.0 s, 26.4 tps, lat 2083.748 ms stddev 4356.546
progress: 180.0 s, 21.2 tps, lat 2977.751 ms stddev 4767.332
progress: 240.0 s, 13.5 tps, lat 5230.657 ms stddev 7029.718
progress: 300.0 s, 42.4 tps, lat 1555.645 ms stddev 1733.152
transaction type: <builtin: TPC-B (sort of)>
scaling factor: 25
query mode: simple
number of clients: 64
number of threads: 8
duration: 300 s
number of transactions actually processed: 14336
latency average = 1342.222 ms
latency stddev = 3043.759 ms
tps = 47.383887 (including connections establishing)
tps = 47.385513 (excluding connections establishing)
-- waiting 0s... (always)
2017.03.09 10:27:56
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 14336 ee0f7bfd9 960d7d79c 3e8af1e9e
cd2bd0395 master
6973 a,b,t,h: 2500000 25 250 14336 ee0f7bfd9 960d7d79c 3e8af1e9e
cd2bd0395 replica ok 578113f12
2017.03.09 10:29:18
-- All is well.
-- 0 seconds total. scale 25 clients 64 -T 300
-- waiting 20s, then end-cleaning
clean-at-end-call
sub_count -ne 0 : deleting sub1 (plain)
ERROR: could not drop the replication slot "sub1" on publisher
DETAIL: The error was: ERROR: replication slot "sub1" is active for PID 10569
sub_count -ne 0 : deleting sub1 (nodrop)
pub_count -ne 0 - deleting pub1
pub_repl_slot_count -ne 0 - deleting (sub1)
ERROR: replication slot "sub1" is active for PID 10569
pub_count 0
pub_repl_slot_count 1
sub_count 0
sub_repl_slot_count 0
-- imperfect cleanup, pg_waldump to unclean.20170309_1021.txt.bz2, waiting 60
s, then exit
-- testset.sh: waiting 10s...
========= iteration 2 -- 2 of 10 =========
============================================================================
-- scale 25 clients 64 duration 300 CLEAN_ONLY=
============================================================================
-- hostname: barzoi
-- timestamp: 20170309_1021
-- master_start_time 2017-03-08 12:04:02.127127+01 replica_start_time
2017-03-08 12:04:02.12713+01
-- master patch-md5 [59c92165d4a328d68450ef0e922c0a42]
-- replica patch-md5 [59c92165d4a328d68450ef0e922c0a42] (ok)
-- synchronous_commit, master [on] replica [off]
-- master_assert [on] replica_assert [on]
-- self md5 87554cfed7cda67ad292b6481e1b8b41 ./pgbench_derail2.sh
clean-at-start-call
pub_repl_slot_count -ne 0 - deleting (sub1)
pg_drop_replication_slot
--------------------------
(1 row)
creating tables...
1596800 of 2500000 tuples (63%) done (elapsed 5.09 s, remaining 2.88 s)
2500000 of 2500000 tuples (100%) done (elapsed 7.88 s, remaining 0.00 s)
vacuum...
set primary keys...
done.
create publication pub1 for all tables;
create subscription sub1 connection 'port=6972' publication pub1 with
(disabled);
alter subscription sub1 enable;
-- pgbench -c 64 -j 8 -T 300 -P 60 -n -- scale 25
progress: 60.0 s, 129.0 tps, lat 493.130 ms stddev 635.654
progress: 120.0 s, 34.0 tps, lat 1679.787 ms stddev 3808.253
progress: 180.0 s, 25.6 tps, lat 2773.775 ms stddev 4709.481
progress: 240.0 s, 26.7 tps, lat 2119.122 ms stddev 3447.122
progress: 300.0 s, 12.3 tps, lat 5411.023 ms stddev 6659.422
transaction type: <builtin: TPC-B (sort of)>
scaling factor: 25
query mode: simple
number of clients: 64
number of threads: 8
duration: 300 s
number of transactions actually processed: 13718
latency average = 1415.080 ms
latency stddev = 3258.969 ms
tps = 44.813091 (including connections establishing)
tps = 44.814631 (excluding connections establishing)
-- waiting 0s... (always)
2017.03.09 10:37:46
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 13718 73599bbb1 302956aac 4bf2f7e03
0b5a112ec master
6973 a,b,t,h: 2500000 25 250 12674 b5fc0c15f 7b62045fe b710b85d1
4e5c8b3da replica NOK 22200d2fa
2017.03.09 10:38:49
-- wait another 5 s (total 0 s) (unchanged 0)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 13718 73599bbb1 302956aac 4bf2f7e03
0b5a112ec master
6973 a,b,t,h: 2500000 25 250 12674 b5fc0c15f 7b62045fe b710b85d1
4e5c8b3da replica NOK 22200d2fa
-- wait another 5 s (total 5 s) (unchanged 1)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 13718 73599bbb1 302956aac 4bf2f7e03
0b5a112ec master
6973 a,b,t,h: 2500000 25 250 12674 b5fc0c15f 7b62045fe b710b85d1
4e5c8b3da replica NOK 22200d2fa
-- wait another 5 s (total 10 s) (unchanged 2)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 13718 73599bbb1 302956aac 4bf2f7e03
0b5a112ec master
6973 a,b,t,h: 2500000 25 250 12674 b5fc0c15f 7b62045fe b710b85d1
4e5c8b3da replica NOK 22200d2fa
-- wait another 5 s (total 15 s) (unchanged 3)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 13718 73599bbb1 302956aac 4bf2f7e03
0b5a112ec master
6973 a,b,t,h: 2500000 25 250 12674 b5fc0c15f 7b62045fe b710b85d1
4e5c8b3da replica NOK 22200d2fa
-- wait another 5 s (total 20 s) (unchanged 4)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 13718 73599bbb1 302956aac 4bf2f7e03
0b5a112ec master
6973 a,b,t,h: 2500000 25 250 12674 b5fc0c15f 7b62045fe b710b85d1
4e5c8b3da replica NOK 22200d2fa
table pg_subscription_rel; table pg_replication_origin_status;
srsubid | srrelid | srsubstate | srsublsn
---------+---------+------------+-------------
37231 | 37203 | r | 27/624E1408
37231 | 37200 | r | 27/62758800
37231 | 37206 | r | 27/62860B18
37231 | 37211 | r | 27/629EE990
(4 rows)
local_id | external_id | remote_lsn | local_lsn
----------+-------------+-------------+-------------
1 | pg_37231 | 27/62C09A50 | 48/CA986BF8
(1 row)
table pg_replication_slots;
slot_name | plugin | slot_type | datoid | database | temporary | active |
active_pid | xmin | catalog_xmin | restart_lsn | confirmed_flush_lsn
-----------+----------+-----------+--------+----------+-----------+--------+------------+------+--------------+-------------+---------------------
sub1 | pgoutput | logical | 16384 | testdb | f | f |
| | 5692123 | 27/62AEBDC8 | 27/62C09A50
(1 row)
-- parsing
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/000000010000002700000069
1]
-- walf
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/000000010000002700000069]
-- bz2f [waldump.20170309_1021_1039.1.5.000000010000002700000069.txt.bz2]
-- lines 2664
-- (before) pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/000000010000002700000069
-- file:
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/000000010000002700000069
-- 2664 lines
-- pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/000000010000002700000069
2>&1 | bzip2 > waldump.20170309_1021_1039.1.5.000000010000002700000069.txt.bz2
-- parsing
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/0000000100000048000000DD
2]
-- walf
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/0000000100000048000000DD]
-- bz2f [waldump.20170309_1021_1039.2.5.000000010000002700000069.txt.bz2]
-- lines 7497
-- (before) pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/0000000100000048000000DD
-- file:
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/0000000100000048000000DD
-- 7497 lines
-- pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/0000000100000048000000DD
2>&1 | bzip2 > waldump.20170309_1021_1039.2.5.000000010000002700000069.txt.bz2
-- wait another 5 s (total 25 s) (unchanged 5)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 13718 73599bbb1 302956aac 4bf2f7e03
0b5a112ec master
6973 a,b,t,h: 2500000 25 250 12674 b5fc0c15f 7b62045fe b710b85d1
4e5c8b3da replica NOK 22200d2fa
-- wait another 5 s (total 30 s) (unchanged 6)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 13718 73599bbb1 302956aac 4bf2f7e03
0b5a112ec master
6973 a,b,t,h: 2500000 25 250 12674 b5fc0c15f 7b62045fe b710b85d1
4e5c8b3da replica NOK 22200d2fa
-- wait another 5 s (total 35 s) (unchanged 7)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 13718 73599bbb1 302956aac 4bf2f7e03
0b5a112ec master
6973 a,b,t,h: 2500000 25 250 12674 b5fc0c15f 7b62045fe b710b85d1
4e5c8b3da replica NOK 22200d2fa
-- wait another 5 s (total 40 s) (unchanged 8)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 13718 73599bbb1 302956aac 4bf2f7e03
0b5a112ec master
6973 a,b,t,h: 2500000 25 250 12674 b5fc0c15f 7b62045fe b710b85d1
4e5c8b3da replica NOK 22200d2fa
-- wait another 5 s (total 45 s) (unchanged 9)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 13718 73599bbb1 302956aac 4bf2f7e03
0b5a112ec master
6973 a,b,t,h: 2500000 25 250 12674 b5fc0c15f 7b62045fe b710b85d1
4e5c8b3da replica NOK 22200d2fa
-- wait another 5 s (total 50 s) (unchanged 10)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 13718 73599bbb1 302956aac 4bf2f7e03
0b5a112ec master
6973 a,b,t,h: 2500000 25 250 12674 b5fc0c15f 7b62045fe b710b85d1
4e5c8b3da replica NOK 22200d2fa
-- wait another 5 s (total 55 s) (unchanged 11)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 13718 73599bbb1 302956aac 4bf2f7e03
0b5a112ec master
6973 a,b,t,h: 2500000 25 250 12674 b5fc0c15f 7b62045fe b710b85d1
4e5c8b3da replica NOK 22200d2fa
-- wait another 5 s (total 60 s) (unchanged 12)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 13718 73599bbb1 302956aac 4bf2f7e03
0b5a112ec master
6973 a,b,t,h: 2500000 25 250 12674 b5fc0c15f 7b62045fe b710b85d1
4e5c8b3da replica NOK 22200d2fa
-- wait another 5 s (total 65 s) (unchanged 13)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 13718 73599bbb1 302956aac 4bf2f7e03
0b5a112ec master
6973 a,b,t,h: 2500000 25 250 12674 b5fc0c15f 7b62045fe b710b85d1
4e5c8b3da replica NOK 22200d2fa
-- wait another 5 s (total 70 s) (unchanged 14)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 13718 73599bbb1 302956aac 4bf2f7e03
0b5a112ec master
6973 a,b,t,h: 2500000 25 250 12674 b5fc0c15f 7b62045fe b710b85d1
4e5c8b3da replica NOK 22200d2fa
-- wait another 5 s (total 75 s) (unchanged 15)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 13718 73599bbb1 302956aac 4bf2f7e03
0b5a112ec master
6973 a,b,t,h: 2500000 25 250 12674 b5fc0c15f 7b62045fe b710b85d1
4e5c8b3da replica NOK 22200d2fa
-- wait another 5 s (total 80 s) (unchanged 16)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 13718 73599bbb1 302956aac 4bf2f7e03
0b5a112ec master
6973 a,b,t,h: 2500000 25 250 12674 b5fc0c15f 7b62045fe b710b85d1
4e5c8b3da replica NOK 22200d2fa
-- wait another 5 s (total 85 s) (unchanged 17)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 13718 73599bbb1 302956aac 4bf2f7e03
0b5a112ec master
6973 a,b,t,h: 2500000 25 250 12674 b5fc0c15f 7b62045fe b710b85d1
4e5c8b3da replica NOK 22200d2fa
-- wait another 5 s (total 90 s) (unchanged 18)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 13718 73599bbb1 302956aac 4bf2f7e03
0b5a112ec master
6973 a,b,t,h: 2500000 25 250 12674 b5fc0c15f 7b62045fe b710b85d1
4e5c8b3da replica NOK 22200d2fa
-- wait another 5 s (total 95 s) (unchanged 19)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 13718 73599bbb1 302956aac 4bf2f7e03
0b5a112ec master
6973 a,b,t,h: 2500000 25 250 12674 b5fc0c15f 7b62045fe b710b85d1
4e5c8b3da replica NOK 22200d2fa
-- wait another 5 s (total 100 s) (unchanged 20)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 13718 73599bbb1 302956aac 4bf2f7e03
0b5a112ec master
6973 a,b,t,h: 2500000 25 250 12674 b5fc0c15f 7b62045fe b710b85d1
4e5c8b3da replica NOK 22200d2fa
-- Not good, but breaking out of wait (21 times no change)
table pg_subscription_rel; table pg_replication_origin_status;
srsubid | srrelid | srsubstate | srsublsn
---------+---------+------------+-------------
37231 | 37203 | r | 27/624E1408
37231 | 37200 | r | 27/62758800
37231 | 37206 | r | 27/62860B18
37231 | 37211 | r | 27/629EE990
(4 rows)
local_id | external_id | remote_lsn | local_lsn
----------+-------------+-------------+-------------
1 | pg_37231 | 27/62C09A50 | 48/CA986BF8
(1 row)
table pg_replication_slots;
slot_name | plugin | slot_type | datoid | database | temporary | active |
active_pid | xmin | catalog_xmin | restart_lsn | confirmed_flush_lsn
-----------+----------+-----------+--------+----------+-----------+--------+------------+------+--------------+-------------+---------------------
sub1 | pgoutput | logical | 16384 | testdb | f | f |
| | 5692123 | 27/62AEBDC8 | 27/62C09A50
(1 row)
-- parsing
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/000000010000002700000069
1]
-- walf
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/000000010000002700000069]
-- bz2f [waldump.20170309_1021_1043.1.21.000000010000002700000069.txt.bz2]
-- lines 2664
-- (before) pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/000000010000002700000069
-- file:
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/000000010000002700000069
-- 2664 lines
-- pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/000000010000002700000069
2>&1 | bzip2 > waldump.20170309_1021_1043.1.21.000000010000002700000069.txt.bz2
-- parsing
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/0000000100000048000000DD
2]
-- walf
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/0000000100000048000000DD]
-- bz2f [waldump.20170309_1021_1043.2.21.000000010000002700000069.txt.bz2]
-- lines 12019
-- (before) pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/0000000100000048000000DD
-- file:
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/0000000100000048000000DD
-- 12019 lines
-- pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/0000000100000048000000DD
2>&1 | bzip2 > waldump.20170309_1021_1043.2.21.000000010000002700000069.txt.bz2
-- (wait_total 105 s)
-- waiting 20s, then end-cleaning
clean-at-end-call
sub_count -ne 0 : deleting sub1 (plain)
sub_count -ne 0 : deleting sub1 (nodrop)
pub_count -ne 0 - deleting pub1
-- testset.sh: waiting 10s...
========= iteration 3 -- 3 of 10 =========
============================================================================
-- scale 25 clients 64 duration 300 CLEAN_ONLY=
============================================================================
-- hostname: barzoi
-- timestamp: 20170309_1021
-- master_start_time 2017-03-08 12:04:02.127127+01 replica_start_time
2017-03-08 12:04:02.12713+01
-- master patch-md5 [59c92165d4a328d68450ef0e922c0a42]
-- replica patch-md5 [59c92165d4a328d68450ef0e922c0a42] (ok)
-- synchronous_commit, master [on] replica [off]
-- master_assert [on] replica_assert [on]
-- self md5 87554cfed7cda67ad292b6481e1b8b41 ./pgbench_derail2.sh
clean-at-start-call
creating tables...
1780100 of 2500000 tuples (71%) done (elapsed 5.17 s, remaining 2.09 s)
2500000 of 2500000 tuples (100%) done (elapsed 7.40 s, remaining 0.00 s)
vacuum...
set primary keys...
done.
create publication pub1 for all tables;
create subscription sub1 connection 'port=6972' publication pub1 with
(disabled);
alter subscription sub1 enable;
-- pgbench -c 64 -j 8 -T 300 -P 60 -n -- scale 25
progress: 60.0 s, 128.6 tps, lat 492.297 ms stddev 636.199
progress: 120.0 s, 31.9 tps, lat 1623.134 ms stddev 3812.437
progress: 180.0 s, 14.6 tps, lat 5168.904 ms stddev 8687.071
progress: 240.0 s, 63.9 tps, lat 1015.973 ms stddev 1480.597
progress: 300.0 s, 85.5 tps, lat 675.831 ms stddev 1752.534
transaction type: <builtin: TPC-B (sort of)>
scaling factor: 25
query mode: simple
number of clients: 64
number of threads: 8
duration: 300 s
number of transactions actually processed: 19545
latency average = 994.479 ms
latency stddev = 2740.546 ms
tps = 62.971798 (including connections establishing)
tps = 62.973751 (excluding connections establishing)
-- waiting 0s... (always)
2017.03.09 10:49:52
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 19545 271cec7ed d95d3475e 3091f5a92
383e94433 master
6973 a,b,t,h: 2500000 25 250 9349 e7c275071 5ff8fa276 a72875613
c7f4ae66f replica NOK aa90d9a4c
2017.03.09 10:51:00
-- wait another 5 s (total 0 s) (unchanged 0)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 19545 271cec7ed d95d3475e 3091f5a92
383e94433 master
6973 a,b,t,h: 2500000 25 250 9349 e7c275071 5ff8fa276 a72875613
c7f4ae66f replica NOK aa90d9a4c
-- wait another 5 s (total 5 s) (unchanged 1)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 19545 271cec7ed d95d3475e 3091f5a92
383e94433 master
6973 a,b,t,h: 2500000 25 250 9349 e7c275071 5ff8fa276 a72875613
c7f4ae66f replica NOK aa90d9a4c
-- wait another 5 s (total 10 s) (unchanged 2)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 19545 271cec7ed d95d3475e 3091f5a92
383e94433 master
6973 a,b,t,h: 2500000 25 250 9349 e7c275071 5ff8fa276 a72875613
c7f4ae66f replica NOK aa90d9a4c
-- wait another 5 s (total 15 s) (unchanged 3)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 19545 271cec7ed d95d3475e 3091f5a92
383e94433 master
6973 a,b,t,h: 2500000 25 250 9349 e7c275071 5ff8fa276 a72875613
c7f4ae66f replica NOK aa90d9a4c
-- wait another 5 s (total 20 s) (unchanged 4)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 19545 271cec7ed d95d3475e 3091f5a92
383e94433 master
6973 a,b,t,h: 2500000 25 250 9349 e7c275071 5ff8fa276 a72875613
c7f4ae66f replica NOK aa90d9a4c
table pg_subscription_rel; table pg_replication_origin_status;
srsubid | srrelid | srsubstate | srsublsn
---------+---------+------------+-------------
37267 | 37239 | r | 27/7F2020D8
37267 | 37236 | r | 27/81222AD0
37267 | 37242 | r | 27/81834060
37267 | 37247 | s | 27/828EA980
(4 rows)
local_id | external_id | remote_lsn | local_lsn
----------+-------------+-------------+------------
1 | pg_37267 | 27/82661788 | 49/D12C0E8
(1 row)
table pg_replication_slots;
slot_name | plugin | slot_type | datoid | database | temporary | active |
active_pid | xmin | catalog_xmin | restart_lsn | confirmed_flush_lsn
-----------+----------+-----------+--------+----------+-----------+--------+------------+------+--------------+-------------+---------------------
sub1 | pgoutput | logical | 16384 | testdb | f | f |
| | 5701209 | 27/816FDB30 | 27/82661788
(1 row)
-- parsing
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/000000010000002700000090
1]
-- walf
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/000000010000002700000090]
-- bz2f [waldump.20170309_1021_1052.1.5.000000010000002700000090.txt.bz2]
-- lines 500
-- (before) pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/000000010000002700000090
-- file:
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/000000010000002700000090
-- 500 lines
-- pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/000000010000002700000090
2>&1 | bzip2 > waldump.20170309_1021_1052.1.5.000000010000002700000090.txt.bz2
-- parsing
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/000000010000004900000017
2]
-- walf
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/000000010000004900000017]
-- bz2f [waldump.20170309_1021_1052.2.5.000000010000002700000090.txt.bz2]
-- lines 446
-- (before) pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/000000010000004900000017
-- file:
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/000000010000004900000017
-- 446 lines
-- pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/000000010000004900000017
2>&1 | bzip2 > waldump.20170309_1021_1052.2.5.000000010000002700000090.txt.bz2
-- wait another 5 s (total 25 s) (unchanged 5)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 19545 271cec7ed d95d3475e 3091f5a92
383e94433 master
6973 a,b,t,h: 2500000 25 250 9349 e7c275071 5ff8fa276 a72875613
c7f4ae66f replica NOK aa90d9a4c
-- wait another 5 s (total 30 s) (unchanged 6)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 19545 271cec7ed d95d3475e 3091f5a92
383e94433 master
6973 a,b,t,h: 2500000 25 250 9349 e7c275071 5ff8fa276 a72875613
c7f4ae66f replica NOK aa90d9a4c
-- wait another 5 s (total 35 s) (unchanged 7)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 19545 271cec7ed d95d3475e 3091f5a92
383e94433 master
6973 a,b,t,h: 2500000 25 250 9349 e7c275071 5ff8fa276 a72875613
c7f4ae66f replica NOK aa90d9a4c
-- wait another 5 s (total 40 s) (unchanged 8)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 19545 271cec7ed d95d3475e 3091f5a92
383e94433 master
6973 a,b,t,h: 2500000 25 250 9349 e7c275071 5ff8fa276 a72875613
c7f4ae66f replica NOK aa90d9a4c
-- wait another 5 s (total 45 s) (unchanged 9)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 19545 271cec7ed d95d3475e 3091f5a92
383e94433 master
6973 a,b,t,h: 2500000 25 250 9349 e7c275071 5ff8fa276 a72875613
c7f4ae66f replica NOK aa90d9a4c
-- wait another 5 s (total 50 s) (unchanged 10)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 19545 271cec7ed d95d3475e 3091f5a92
383e94433 master
6973 a,b,t,h: 2500000 25 250 9349 e7c275071 5ff8fa276 a72875613
c7f4ae66f replica NOK aa90d9a4c
-- wait another 5 s (total 55 s) (unchanged 11)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 19545 271cec7ed d95d3475e 3091f5a92
383e94433 master
6973 a,b,t,h: 2500000 25 250 9349 e7c275071 5ff8fa276 a72875613
c7f4ae66f replica NOK aa90d9a4c
-- wait another 5 s (total 60 s) (unchanged 12)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 19545 271cec7ed d95d3475e 3091f5a92
383e94433 master
6973 a,b,t,h: 2500000 25 250 9349 e7c275071 5ff8fa276 a72875613
c7f4ae66f replica NOK aa90d9a4c
-- wait another 5 s (total 65 s) (unchanged 13)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 19545 271cec7ed d95d3475e 3091f5a92
383e94433 master
6973 a,b,t,h: 2500000 25 250 9349 e7c275071 5ff8fa276 a72875613
c7f4ae66f replica NOK aa90d9a4c
-- wait another 5 s (total 70 s) (unchanged 14)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 19545 271cec7ed d95d3475e 3091f5a92
383e94433 master
6973 a,b,t,h: 2500000 25 250 9349 e7c275071 5ff8fa276 a72875613
c7f4ae66f replica NOK aa90d9a4c
-- wait another 5 s (total 75 s) (unchanged 15)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 19545 271cec7ed d95d3475e 3091f5a92
383e94433 master
6973 a,b,t,h: 2500000 25 250 9349 e7c275071 5ff8fa276 a72875613
c7f4ae66f replica NOK aa90d9a4c
-- wait another 5 s (total 80 s) (unchanged 16)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 19545 271cec7ed d95d3475e 3091f5a92
383e94433 master
6973 a,b,t,h: 2500000 25 250 9349 e7c275071 5ff8fa276 a72875613
c7f4ae66f replica NOK aa90d9a4c
-- wait another 5 s (total 85 s) (unchanged 17)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 19545 271cec7ed d95d3475e 3091f5a92
383e94433 master
6973 a,b,t,h: 2500000 25 250 9349 e7c275071 5ff8fa276 a72875613
c7f4ae66f replica NOK aa90d9a4c
-- wait another 5 s (total 90 s) (unchanged 18)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 19545 271cec7ed d95d3475e 3091f5a92
383e94433 master
6973 a,b,t,h: 2500000 25 250 9349 e7c275071 5ff8fa276 a72875613
c7f4ae66f replica NOK aa90d9a4c
-- wait another 5 s (total 95 s) (unchanged 19)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 19545 271cec7ed d95d3475e 3091f5a92
383e94433 master
6973 a,b,t,h: 2500000 25 250 9349 e7c275071 5ff8fa276 a72875613
c7f4ae66f replica NOK aa90d9a4c
-- wait another 5 s (total 100 s) (unchanged 20)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 19545 271cec7ed d95d3475e 3091f5a92
383e94433 master
6973 a,b,t,h: 2500000 25 250 9349 e7c275071 5ff8fa276 a72875613
c7f4ae66f replica NOK aa90d9a4c
-- Not good, but breaking out of wait (21 times no change)
table pg_subscription_rel; table pg_replication_origin_status;
srsubid | srrelid | srsubstate | srsublsn
---------+---------+------------+-------------
37267 | 37239 | r | 27/7F2020D8
37267 | 37236 | r | 27/81222AD0
37267 | 37242 | r | 27/81834060
37267 | 37247 | s | 27/828EA980
(4 rows)
local_id | external_id | remote_lsn | local_lsn
----------+-------------+-------------+------------
1 | pg_37267 | 27/82661788 | 49/D12C0E8
(1 row)
table pg_replication_slots;
slot_name | plugin | slot_type | datoid | database | temporary | active |
active_pid | xmin | catalog_xmin | restart_lsn | confirmed_flush_lsn
-----------+----------+-----------+--------+----------+-----------+--------+------------+------+--------------+-------------+---------------------
sub1 | pgoutput | logical | 16384 | testdb | f | f |
| | 5701209 | 27/816FDB30 | 27/82661788
(1 row)
-- parsing
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/000000010000002700000090
1]
-- walf
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/000000010000002700000090]
-- bz2f [waldump.20170309_1021_1055.1.21.000000010000002700000090.txt.bz2]
-- lines 503
-- (before) pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/000000010000002700000090
-- file:
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/000000010000002700000090
-- 503 lines
-- pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/000000010000002700000090
2>&1 | bzip2 > waldump.20170309_1021_1055.1.21.000000010000002700000090.txt.bz2
-- parsing
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/000000010000004900000017
2]
-- walf
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/000000010000004900000017]
-- bz2f [waldump.20170309_1021_1055.2.21.000000010000002700000090.txt.bz2]
-- lines 687
-- (before) pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/000000010000004900000017
-- file:
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/000000010000004900000017
-- 687 lines
-- pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/000000010000004900000017
2>&1 | bzip2 > waldump.20170309_1021_1055.2.21.000000010000002700000090.txt.bz2
-- (wait_total 105 s)
-- waiting 20s, then end-cleaning
clean-at-end-call
sub_count -ne 0 : deleting sub1 (plain)
sub_count -ne 0 : deleting sub1 (nodrop)
pub_count -ne 0 - deleting pub1
-- testset.sh: waiting 10s...
========= iteration 4 -- 4 of 10 =========
============================================================================
-- scale 25 clients 64 duration 300 CLEAN_ONLY=
============================================================================
-- hostname: barzoi
-- timestamp: 20170309_1021
-- master_start_time 2017-03-08 12:04:02.127127+01 replica_start_time
2017-03-08 12:04:02.12713+01
-- master patch-md5 [59c92165d4a328d68450ef0e922c0a42]
-- replica patch-md5 [59c92165d4a328d68450ef0e922c0a42] (ok)
-- synchronous_commit, master [on] replica [off]
-- master_assert [on] replica_assert [on]
-- self md5 87554cfed7cda67ad292b6481e1b8b41 ./pgbench_derail2.sh
clean-at-start-call
creating tables...
1701200 of 2500000 tuples (68%) done (elapsed 5.00 s, remaining 2.35 s)
2500000 of 2500000 tuples (100%) done (elapsed 7.98 s, remaining 0.00 s)
vacuum...
set primary keys...
done.
create publication pub1 for all tables;
create subscription sub1 connection 'port=6972' publication pub1 with
(disabled);
alter subscription sub1 enable;
-- pgbench -c 64 -j 8 -T 300 -P 60 -n -- scale 25
progress: 60.0 s, 152.7 tps, lat 411.175 ms stddev 554.315
progress: 120.0 s, 34.8 tps, lat 1770.342 ms stddev 3061.939
progress: 180.0 s, 9.3 tps, lat 6638.393 ms stddev 5392.463
progress: 240.0 s, 49.1 tps, lat 1268.013 ms stddev 2752.765
progress: 300.0 s, 15.5 tps, lat 4434.394 ms stddev 5996.309
transaction type: <builtin: TPC-B (sort of)>
scaling factor: 25
query mode: simple
number of clients: 64
number of threads: 8
duration: 300 s
number of transactions actually processed: 15745
latency average = 1221.427 ms
latency stddev = 2851.259 ms
tps = 52.289500 (including connections establishing)
tps = 52.291391 (excluding connections establishing)
-- waiting 0s... (always)
2017.03.09 11:02:03
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 15745 9337c5be5 bf71d5c15 15350693f
a92a36f7e master
6973 a,b,t,h: 2500000 25 250 15745 9337c5be5 bf71d5c15 15350693f
a92a36f7e replica ok 61d31684c
2017.03.09 11:04:07
-- All is well.
-- 0 seconds total. scale 25 clients 64 -T 300
-- waiting 20s, then end-cleaning
clean-at-end-call
sub_count -ne 0 : deleting sub1 (plain)
sub_count -ne 0 : deleting sub1 (nodrop)
pub_count -ne 0 - deleting pub1
-- testset.sh: waiting 10s...
========= iteration 5 -- 5 of 10 =========
============================================================================
-- scale 25 clients 64 duration 300 CLEAN_ONLY=
============================================================================
-- hostname: barzoi
-- timestamp: 20170309_1021
-- master_start_time 2017-03-08 12:04:02.127127+01 replica_start_time
2017-03-08 12:04:02.12713+01
-- master patch-md5 [59c92165d4a328d68450ef0e922c0a42]
-- replica patch-md5 [59c92165d4a328d68450ef0e922c0a42] (ok)
-- synchronous_commit, master [on] replica [off]
-- master_assert [on] replica_assert [on]
-- self md5 87554cfed7cda67ad292b6481e1b8b41 ./pgbench_derail2.sh
clean-at-start-call
creating tables...
1635100 of 2500000 tuples (65%) done (elapsed 5.00 s, remaining 2.64 s)
2500000 of 2500000 tuples (100%) done (elapsed 7.34 s, remaining 0.00 s)
vacuum...
set primary keys...
done.
create publication pub1 for all tables;
create subscription sub1 connection 'port=6972' publication pub1 with
(disabled);
alter subscription sub1 enable;
-- pgbench -c 64 -j 8 -T 300 -P 60 -n -- scale 25
progress: 60.0 s, 99.9 tps, lat 633.458 ms stddev 811.704
progress: 120.0 s, 57.3 tps, lat 969.062 ms stddev 2178.241
progress: 180.0 s, 32.8 tps, lat 2181.112 ms stddev 4917.504
progress: 240.0 s, 58.4 tps, lat 1103.141 ms stddev 2466.176
progress: 300.0 s, 42.8 tps, lat 1456.959 ms stddev 3386.565
transaction type: <builtin: TPC-B (sort of)>
scaling factor: 25
query mode: simple
number of clients: 64
number of threads: 8
duration: 300 s
number of transactions actually processed: 17545
latency average = 1098.486 ms
latency stddev = 2654.628 ms
tps = 57.833132 (including connections establishing)
tps = 57.835168 (excluding connections establishing)
-- waiting 0s... (always)
2017.03.09 11:10:52
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 17545 2d620e07c 592b6ad24 636bd4ee3
4b44672dd master
6973 a,b,t,h: 2500000 25 250 9293 6ba849c83 c2a81c550 922a39571
714d7593b replica NOK d574a9304
2017.03.09 11:11:58
-- wait another 5 s (total 0 s) (unchanged 0)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 17545 2d620e07c 592b6ad24 636bd4ee3
4b44672dd master
6973 a,b,t,h: 2500000 25 250 9293 6ba849c83 c2a81c550 922a39571
714d7593b replica NOK d574a9304
-- wait another 5 s (total 5 s) (unchanged 1)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 17545 2d620e07c 592b6ad24 636bd4ee3
4b44672dd master
6973 a,b,t,h: 2500000 25 250 9293 6ba849c83 c2a81c550 922a39571
714d7593b replica NOK d574a9304
-- wait another 5 s (total 10 s) (unchanged 2)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 17545 2d620e07c 592b6ad24 636bd4ee3
4b44672dd master
6973 a,b,t,h: 2500000 25 250 9293 6ba849c83 c2a81c550 922a39571
714d7593b replica NOK d574a9304
-- wait another 5 s (total 15 s) (unchanged 3)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 17545 2d620e07c 592b6ad24 636bd4ee3
4b44672dd master
6973 a,b,t,h: 2500000 25 250 9293 6ba849c83 c2a81c550 922a39571
714d7593b replica NOK d574a9304
-- wait another 5 s (total 20 s) (unchanged 4)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 17545 2d620e07c 592b6ad24 636bd4ee3
4b44672dd master
6973 a,b,t,h: 2500000 25 250 9293 6ba849c83 c2a81c550 922a39571
714d7593b replica NOK d574a9304
table pg_subscription_rel; table pg_replication_origin_status;
srsubid | srrelid | srsubstate | srsublsn
---------+---------+------------+-------------
37340 | 37312 | r | 27/D1925440
37340 | 37309 | r | 27/D3B540B0
37340 | 37315 | r | 27/D45B3928
37340 | 37320 | r | 27/D5588F40
(4 rows)
local_id | external_id | remote_lsn | local_lsn
----------+-------------+-------------+-------------
1 | pg_37340 | 27/D66818D8 | 49/8C1622A0
(1 row)
table pg_replication_slots;
slot_name | plugin | slot_type | datoid | database | temporary | active |
active_pid | xmin | catalog_xmin | restart_lsn | confirmed_flush_lsn
-----------+----------+-----------+--------+----------+-----------+--------+------------+------+--------------+-------------+---------------------
sub1 | pgoutput | logical | 16384 | testdb | f | f |
| | 5737826 | 27/D533F9B0 | 27/D66818D8
(1 row)
-- parsing
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/0000000100000027000000E2
1]
-- walf
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/0000000100000027000000E2]
-- bz2f [waldump.20170309_1021_1113.1.5.0000000100000027000000E2.txt.bz2]
-- lines 2868
-- (before) pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/0000000100000027000000E2
-- file:
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/0000000100000027000000E2
-- 2868 lines
-- pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/0000000100000027000000E2
2>&1 | bzip2 > waldump.20170309_1021_1113.1.5.0000000100000027000000E2.txt.bz2
-- parsing
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/000000010000004900000098
2]
-- walf
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/000000010000004900000098]
-- bz2f [waldump.20170309_1021_1113.2.5.0000000100000027000000E2.txt.bz2]
-- lines 696
-- (before) pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/000000010000004900000098
-- file:
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/000000010000004900000098
-- 696 lines
-- pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/000000010000004900000098
2>&1 | bzip2 > waldump.20170309_1021_1113.2.5.0000000100000027000000E2.txt.bz2
-- wait another 5 s (total 25 s) (unchanged 5)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 17545 2d620e07c 592b6ad24 636bd4ee3
4b44672dd master
6973 a,b,t,h: 2500000 25 250 9293 6ba849c83 c2a81c550 922a39571
714d7593b replica NOK d574a9304
-- wait another 5 s (total 30 s) (unchanged 6)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 17545 2d620e07c 592b6ad24 636bd4ee3
4b44672dd master
6973 a,b,t,h: 2500000 25 250 9293 6ba849c83 c2a81c550 922a39571
714d7593b replica NOK d574a9304
-- wait another 5 s (total 35 s) (unchanged 7)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 17545 2d620e07c 592b6ad24 636bd4ee3
4b44672dd master
6973 a,b,t,h: 2500000 25 250 9293 6ba849c83 c2a81c550 922a39571
714d7593b replica NOK d574a9304
-- wait another 5 s (total 40 s) (unchanged 8)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 17545 2d620e07c 592b6ad24 636bd4ee3
4b44672dd master
6973 a,b,t,h: 2500000 25 250 9293 6ba849c83 c2a81c550 922a39571
714d7593b replica NOK d574a9304
-- wait another 5 s (total 45 s) (unchanged 9)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 17545 2d620e07c 592b6ad24 636bd4ee3
4b44672dd master
6973 a,b,t,h: 2500000 25 250 9293 6ba849c83 c2a81c550 922a39571
714d7593b replica NOK d574a9304
-- wait another 5 s (total 50 s) (unchanged 10)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 17545 2d620e07c 592b6ad24 636bd4ee3
4b44672dd master
6973 a,b,t,h: 2500000 25 250 9293 6ba849c83 c2a81c550 922a39571
714d7593b replica NOK d574a9304
-- wait another 5 s (total 55 s) (unchanged 11)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 17545 2d620e07c 592b6ad24 636bd4ee3
4b44672dd master
6973 a,b,t,h: 2500000 25 250 9293 6ba849c83 c2a81c550 922a39571
714d7593b replica NOK d574a9304
-- wait another 5 s (total 60 s) (unchanged 12)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 17545 2d620e07c 592b6ad24 636bd4ee3
4b44672dd master
6973 a,b,t,h: 2500000 25 250 9293 6ba849c83 c2a81c550 922a39571
714d7593b replica NOK d574a9304
-- wait another 5 s (total 65 s) (unchanged 13)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 17545 2d620e07c 592b6ad24 636bd4ee3
4b44672dd master
6973 a,b,t,h: 2500000 25 250 9293 6ba849c83 c2a81c550 922a39571
714d7593b replica NOK d574a9304
-- wait another 5 s (total 70 s) (unchanged 14)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 17545 2d620e07c 592b6ad24 636bd4ee3
4b44672dd master
6973 a,b,t,h: 2500000 25 250 9293 6ba849c83 c2a81c550 922a39571
714d7593b replica NOK d574a9304
-- wait another 5 s (total 75 s) (unchanged 15)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 17545 2d620e07c 592b6ad24 636bd4ee3
4b44672dd master
6973 a,b,t,h: 2500000 25 250 9293 6ba849c83 c2a81c550 922a39571
714d7593b replica NOK d574a9304
-- wait another 5 s (total 80 s) (unchanged 16)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 17545 2d620e07c 592b6ad24 636bd4ee3
4b44672dd master
6973 a,b,t,h: 2500000 25 250 9293 6ba849c83 c2a81c550 922a39571
714d7593b replica NOK d574a9304
-- wait another 5 s (total 85 s) (unchanged 17)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 17545 2d620e07c 592b6ad24 636bd4ee3
4b44672dd master
6973 a,b,t,h: 2500000 25 250 9293 6ba849c83 c2a81c550 922a39571
714d7593b replica NOK d574a9304
-- wait another 5 s (total 90 s) (unchanged 18)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 17545 2d620e07c 592b6ad24 636bd4ee3
4b44672dd master
6973 a,b,t,h: 2500000 25 250 9293 6ba849c83 c2a81c550 922a39571
714d7593b replica NOK d574a9304
-- wait another 5 s (total 95 s) (unchanged 19)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 17545 2d620e07c 592b6ad24 636bd4ee3
4b44672dd master
6973 a,b,t,h: 2500000 25 250 9293 6ba849c83 c2a81c550 922a39571
714d7593b replica NOK d574a9304
-- wait another 5 s (total 100 s) (unchanged 20)
-- getting md5 (cb)
6972 a,b,t,h: 2500000 25 250 17545 2d620e07c 592b6ad24 636bd4ee3
4b44672dd master
6973 a,b,t,h: 2500000 25 250 9293 6ba849c83 c2a81c550 922a39571
714d7593b replica NOK d574a9304
-- Not good, but breaking out of wait (21 times no change)
table pg_subscription_rel; table pg_replication_origin_status;
srsubid | srrelid | srsubstate | srsublsn
---------+---------+------------+-------------
37340 | 37312 | r | 27/D1925440
37340 | 37309 | r | 27/D3B540B0
37340 | 37315 | r | 27/D45B3928
37340 | 37320 | r | 27/D5588F40
(4 rows)
local_id | external_id | remote_lsn | local_lsn
----------+-------------+-------------+-------------
1 | pg_37340 | 27/D66818D8 | 49/8C1622A0
(1 row)
table pg_replication_slots;
slot_name | plugin | slot_type | datoid | database | temporary | active |
active_pid | xmin | catalog_xmin | restart_lsn | confirmed_flush_lsn
-----------+----------+-----------+--------+----------+-----------+--------+------------+------+--------------+-------------+---------------------
sub1 | pgoutput | logical | 16384 | testdb | f | f |
| | 5737826 | 27/D533F9B0 | 27/D66818D8
(1 row)
-- parsing
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/0000000100000027000000E2
1]
-- walf
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/0000000100000027000000E2]
-- bz2f [waldump.20170309_1021_1116.1.21.0000000100000027000000E2.txt.bz2]
-- lines 2868
-- (before) pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/0000000100000027000000E2
-- file:
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/0000000100000027000000E2
-- 2868 lines
-- pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication/data/pg_wal/0000000100000027000000E2
2>&1 | bzip2 > waldump.20170309_1021_1116.1.21.0000000100000027000000E2.txt.bz2
-- parsing
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/000000010000004900000098
2]
-- walf
[/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/000000010000004900000098]
-- bz2f [waldump.20170309_1021_1116.2.21.0000000100000027000000E2.txt.bz2]
-- lines 1009
-- (before) pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/000000010000004900000098
-- file:
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/000000010000004900000098
-- 1009 lines
-- pg_waldump
/home/aardvark/pg_stuff/pg_installations/pgsql.logical_replication2/data/pg_wal/000000010000004900000098
2>&1 | bzip2 > waldump.20170309_1021_1116.2.21.0000000100000027000000E2.txt.bz2
-- (wait_total 105 s)
-- waiting 20s, then end-cleaning
clean-at-end-call
sub_count -ne 0 : deleting sub1 (plain)
sub_count -ne 0 : deleting sub1 (nodrop)
pub_count -ne 0 - deleting pub1
-- testset.sh: waiting 10s...
========= iteration 6 -- 6 of 10 =========
============================================================================
-- scale 25 clients 64 duration 300 CLEAN_ONLY=
============================================================================
-- hostname: barzoi
-- timestamp: 20170309_1021
-- master_start_time 2017-03-08 12:04:02.127127+01 replica_start_time
2017-03-08 12:04:02.12713+01
-- master patch-md5 [59c92165d4a328d68450ef0e922c0a42]
-- replica patch-md5 [59c92165d4a328d68450ef0e922c0a42] (ok)
-- synchronous_commit, master [on] replica [off]
-- master_assert [on] replica_assert [on]
-- self md5 87554cfed7cda67ad292b6481e1b8b41 ./pgbench_derail2.sh
clean-at-start-call
creating tables...
1651800 of 2500000 tuples (66%) done (elapsed 5.00 s, remaining 2.57 s)
2500000 of 2500000 tuples (100%) done (elapsed 7.42 s, remaining 0.00 s)
vacuum...
set primary keys...
done.
create publication pub1 for all tables;
create subscription sub1 connection 'port=6972' publication pub1 with
(disabled);
alter subscription sub1 enable;
-- pgbench -c 64 -j 8 -T 300 -P 60 -n -- scale 25
progress: 60.0 s, 143.3 tps, lat 443.151 ms stddev 619.222
progress: 120.0 s, 21.3 tps, lat 2671.388 ms stddev 5356.946
progress: 180.0 s, 51.2 tps, lat 1252.638 ms stddev 2746.218
progress: 240.0 s, 7.1 tps, lat 8288.817 ms stddev 6335.279
progress: 300.0 s, 9.9 tps, lat 7078.697 ms stddev 8657.126
transaction type: <builtin: TPC-B (sort of)>
scaling factor: 25
query mode: simple
number of clients: 64
number of threads: 8
duration: 300 s
number of transactions actually processed: 14030
latency average = 1381.823 ms
latency stddev = 3593.944 ms
tps = 45.248364 (including connections establishing)
tps = 45.249744 (excluding connections establishing)
-- waiting 0s... (always)
2017.03.09 11:23:16
-- getting md5 (cb)
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
