Re: Notify When Streaming Replication Failover Occurred (slave promoted to master).
On 2021-06-14 08:10:58 -0400, Dave Cramer wrote: > On Sun, 13 Jun 2021 at 19:32, Avi Weinberg wrote: > > > I need to take actions when Postgres streaming replication failover > occurred. Is there a way to be notified when Postgres slave becomes > master? > > On the surface this seems like a great idea, however contemplating this a bit > more; where would the signal come from ? Currently the only option I can think > of is to send a NOTIFY. > It seems to me that the Patroni code is a better place to do this from. I agree. That is something Patroni should do, not the database. Maybe Patroni could be extended to invoke a script after taking some action. I know of one program (vip_manager) which monitors patroni state and takes action (enable/disable virtual ip addresses) - that one checks the distributed database (etcd or whatever) periodically, AFAIK. hp -- _ | Peter J. Holzer| Story must make more sense than reality. |_|_) || | | | h...@hjp.at |-- Charles Stross, "Creative writing __/ | http://www.hjp.at/ | challenge!" signature.asc Description: PGP signature
Re: [ext] Re: Losing data because of problematic configuration?
Hi again,
thank you for pinpointing the issue.
I have now updated the table with "ALTER TABLE $table SET LOGGED" (actually
it's a partitioned table and I've altered both the main table and the
partitions).
I wanted to double-check the result and what I found out using "select
relpersistence, relname from pg_class" that, e.g., ${table_name}_383_pkey still
has its relpersistence set to "u" whereas ${table_name}_383 has its
relpersistence set to "p" now.
Does anyone have an idea what I'm doing wrong here?
Thank you!
Manuel
From: Holtgrewe, Manuel
Sent: Tuesday, June 15, 2021 5:53:54 PM
To: Tom Lane
Cc: pgsql-general@lists.postgresql.org
Subject: Re: [ext] Re: Losing data because of problematic configuration?
>> < 2021-06-15 12:33:04.537 CEST > DEBUG: resetting unlogged relations:
>> cleanup 1 init 0
>
> Are you perhaps keeping your data in an UNLOGGED table? If so, resetting
> it to empty after a crash is exactly what's supposed to happen. The
> entire point of UNLOGGED is that the performance benefits come at the
> cost of losing the data on crash.
D'oh!
Yes, that is the case. I once used this but I was convinced that I took this
back in some version. It is not in my main deployment, though. Now I have to
find out (a) why I have diverging deployment and (b) how that bug came about to
be.
Thanks a lot!
From: Tom Lane
Sent: Tuesday, June 15, 2021 3:39:31 PM
To: Holtgrewe, Manuel
Cc: pgsql-general@lists.postgresql.org
Subject: [ext] Re: Losing data because of problematic configuration?
"Holtgrewe, Manuel" writes:
> So it looks as if the database jumps back "half an hour" to ensure consistent
> data. Everything in between is lost.
Postgres does not lose committed data --- if it did, we'd consider that a
fairly serious bug. (Well, there are caveats of course. But most of them
have to do with operating-system crashes or power loss, neither of which
are at stake here.)
I am wondering about this though:
> < 2021-06-15 12:33:04.537 CEST > DEBUG: resetting unlogged relations:
> cleanup 1 init 0
Are you perhaps keeping your data in an UNLOGGED table? If so, resetting
it to empty after a crash is exactly what's supposed to happen. The
entire point of UNLOGGED is that the performance benefits come at the
cost of losing the data on crash.
regards, tom lane
Re: [ext] Re: Losing data because of problematic configuration?
Please ignore this email. I could not reproduce it after all.
--
Dr. Manuel Holtgrewe, Dipl.-Inform.
Bioinformatician
Core Unit Bioinformatics – CUBI
Berlin Institute of Health / Max Delbrück Center for Molecular Medicine in the
Helmholtz Association / Charité – Universitätsmedizin Berlin
Visiting Address: Invalidenstr. 80, 3rd Floor, Room 03 028, 10117 Berlin
Postal Address: Chariteplatz 1, 10117 Berlin
E-Mail: manuel.holtgr...@bihealth.de
Phone: +49 30 450 543 607
Fax: +49 30 450 7 543 901
Web: cubi.bihealth.org www.bihealth.org www.mdc-berlin.de www.charite.de
From: Holtgrewe, Manuel
Sent: Wednesday, June 16, 2021 10:54:49 AM
To: Tom Lane
Cc: pgsql-general@lists.postgresql.org
Subject: Re: [ext] Re: Losing data because of problematic configuration?
Hi again,
thank you for pinpointing the issue.
I have now updated the table with "ALTER TABLE $table SET LOGGED" (actually
it's a partitioned table and I've altered both the main table and the
partitions).
I wanted to double-check the result and what I found out using "select
relpersistence, relname from pg_class" that, e.g., ${table_name}_383_pkey still
has its relpersistence set to "u" whereas ${table_name}_383 has its
relpersistence set to "p" now.
Does anyone have an idea what I'm doing wrong here?
Thank you!
Manuel
From: Holtgrewe, Manuel
Sent: Tuesday, June 15, 2021 5:53:54 PM
To: Tom Lane
Cc: pgsql-general@lists.postgresql.org
Subject: Re: [ext] Re: Losing data because of problematic configuration?
>> < 2021-06-15 12:33:04.537 CEST > DEBUG: resetting unlogged relations:
>> cleanup 1 init 0
>
> Are you perhaps keeping your data in an UNLOGGED table? If so, resetting
> it to empty after a crash is exactly what's supposed to happen. The
> entire point of UNLOGGED is that the performance benefits come at the
> cost of losing the data on crash.
D'oh!
Yes, that is the case. I once used this but I was convinced that I took this
back in some version. It is not in my main deployment, though. Now I have to
find out (a) why I have diverging deployment and (b) how that bug came about to
be.
Thanks a lot!
From: Tom Lane
Sent: Tuesday, June 15, 2021 3:39:31 PM
To: Holtgrewe, Manuel
Cc: pgsql-general@lists.postgresql.org
Subject: [ext] Re: Losing data because of problematic configuration?
"Holtgrewe, Manuel" writes:
> So it looks as if the database jumps back "half an hour" to ensure consistent
> data. Everything in between is lost.
Postgres does not lose committed data --- if it did, we'd consider that a
fairly serious bug. (Well, there are caveats of course. But most of them
have to do with operating-system crashes or power loss, neither of which
are at stake here.)
I am wondering about this though:
> < 2021-06-15 12:33:04.537 CEST > DEBUG: resetting unlogged relations:
> cleanup 1 init 0
Are you perhaps keeping your data in an UNLOGGED table? If so, resetting
it to empty after a crash is exactly what's supposed to happen. The
entire point of UNLOGGED is that the performance benefits come at the
cost of losing the data on crash.
regards, tom lane
Re: some questions regarding replication issues and timeline/history files
Yeah it is latest. I am using Postgres 9.6. Thanks! Sudhakaran On Tue, 15 Jun 2021 at 10:42 PM, Mateusz Henicz wrote: > Do you have "recovery_target_timeline=latest" configured in your > recovery.conf or postgresql.conf? Depending on the version you are using, > up to 11 recovery.conf and postgresql.conf 12+. > > Cheers, > Mateusz > > wt., 15 cze 2021, 22:05 użytkownik email2ssk...@gmail.com < > email2ssk...@gmail.com> napisał: > >> Even I have this problem when I had to recover the database failed >> switchover. >> This is error is new primary server. >> >> < 2021-06-15 16:05:02.480 CEST > ERROR: requested starting point >> AF/7D00 on timeline 1 is not in this server's history >> < 2021-06-15 16:05:02.480 CEST > DETAIL: This server's history forked >> from >> timeline 1 at AF/7C0F8D58. >> >> >> >> -- >> Sent from: >> https://www.postgresql-archive.org/PostgreSQL-general-f1843780.html >> >> >>
Re: query issue
On Wed, 16 Jun 2021 at 18:29, Atul Kumar wrote:
> QUERY PLAN
> Limit (cost=0.43..5529.03 rows=10 width=37) (actual
> time=0.974..12911.087 rows=10 loops=1)
> Output: items._id
> Buffers: shared hit=4838 read=3701
> -> Subquery Scan on items (cost=0.43..1622646.30 rows=2935
> width=37) (actual time=0.972..12911.078 rows=10 loops=1)
> Output: items._id
> Buffers: shared hit=4838 read=3701
> -> Index Scan using sort on
> "op_KFDaBAZDSXc4YYts9"."UserFeedItems" (cost=0.43..1622616.95
> rows=2935 width=50) (actual time=0.970..12911.070 rows=10 loops=1)
> Output: "UserFeedItems"._id, "UserFeedItems".score,
> "UserFeedItems"."updatedAt"
> Filter: (("UserFeedItems".is_deleted = ANY
> ('{t,f}'::boolean[])) AND ("UserFeedItems"."userId" =
> '5d230d67bd99c5001b1ae757'::text) AND ("UserFeedItems"."itemType" <>
> ALL ('{WELCOME_POST,UPLOAD_CONTACTS,BROADCAST_POST}'::text[])))
> Rows Removed by Filter: 15478
> Buffers: shared hit=4838 read=3701
> Planning time: 100.949 ms
> Execution time: 12930.302 ms
It seems to me that this system is pretty slow on I/O. I imagine if
you do: SET track_io_timing = ON: then run EXPLAIN (ANALYZE, BUFFERS)
on the query that you'll see that most of the time is spent doing I/O.
If you're unable to make I/O faster then you might want to upgrade to
a machine that's more likely to be able to keep the working set of
your database in memory.
>From looking at your earlier queries:
> -> Bitmap Heap Scan on "UserFeedItems"
> (cost=131.33..10994.60 rows=2935 width=1304) (actual
> time=26.245..6093.680 rows=3882 loops=1)
> Recheck Cond: ("userId" = '5d230d67bd99c5001b1ae757'::text)
> Filter: ((is_deleted = ANY ('{t,f}'::boolean[])) AND
> ("itemType" <> ALL
> ('{WELCOME_POST,UPLOAD_CONTACTS,BROADCAST_POST}'::text[])))
> Rows Removed by Filter: 1
> Heap Blocks: exact=3804
The bitmap index scan matched 3804 pages and there are only 3882 rows.
That's an average of just over 1 tuple per page. If the table was
clustered by that index then that might help speed up your query, but
since the cluster order is not maintained then it'll likely go out
over time and the query will just become slow again.
If you had been using at least PostgreSQL 12 then you could have
looked into using partitioning. Partitioning does exist before 12,
but it became much better in that version. Partitioning might help
you here if you partitioned by HASH (userid) as you might average a
few more matched rows per page in the bitmap scan and reduce the
number of pages that need to be read from disk. I'm not really sure
how many partitions you'd have to make to get a meaningful improvement
there though. That'll depend on how many users there are and how big
the rows are.
There are also some pretty bad design choices with your table. You
seem to have lots of IDs which are TEXT fields. It's fairly normal
practice in databases not to do that and to use something like INT or
BIGINT. Using TEXT is pretty bad for a few reasons. 1) it makes your
data bigger and reduces cache hit ratios. 2) variable length fields at
the start of tables is not so great as tuple deforming becomes slower
due to there being no fixed offset into columns that come after a
variable-length field.
Anyway, there's quite a lot you could do here to make this query run faster.
David
Re: clear cache in postgresql
On 2021-06-16 14:39:19 +0800, Julien Rouhaud wrote: > On Wed, Jun 16, 2021 at 12:02:52PM +0530, Atul Kumar wrote: > > Sometimes I run a Postgres query it takes 30 seconds. Then, I > > immediately run the same query and it takes 2 seconds. [...] > > Can I force all caches to be cleared for tuning purposes? > > So I need to clear the cache without restarting/rebooting the postgres > > server to check the correct execution plan of my query. > > No, cleaning postgres cache can only be done with a service restart. That > being said, tuning shouldn't be done assuming that there's no cache. I agree mostly, but not entirely. The most important case to optimize is of course the normal case, where at least some of the data will already be cached. Hoewever, I do think it is also important to ensure that the rare cases are still acceptable. If a given operation takes 2 seconds 95 % of the time but 30 seconds 5 % of the time that makes for a poor user experience, expecially if its seemingly at random (because it depends on what other users have done recently). So you may want to investigate those cases, too. hp -- _ | Peter J. Holzer| Story must make more sense than reality. |_|_) || | | | h...@hjp.at |-- Charles Stross, "Creative writing __/ | http://www.hjp.at/ | challenge!" signature.asc Description: PGP signature
Establishing a local connection to PostgreSQL 9.6 takes seconds
In a heavily used production database prod, running a `psql prod` takes
seconds. Once the connection is established, performance of queries is
fine. There are ~2 new usually short-lived connections / second, and a
couple of long-running analytical queries. Connecting to other databases on
the same PostgreSQL server is fast.
Here is what I tried:
-bash-4.2$ date; psql prod -c "SELECT backend_start, xact_start,
query_start FROM pg_stat_activity WHERE pid = (SELECT pg_backend_pid());";
date
Wed Jun 16 09:01:51 EDT 2021
backend_start | xact_start |
query_start
---+---+---
2021-06-16 09:01:51.596197-04 | 2021-06-16 09:01:57.979979-04 | 2021-06-16
09:01:57.979979-04
(1 row)
Wed Jun 16 09:01:57 EDT 2021
So the backend started quickly, but it took 6 seconds to start running the
query.
I used
ps --sort=start_time -elfy | grep "postgres prod .*startup" | head -n1 |
awk '{print $3}'
to identify the PID the most recent pg backend started by myself in startup
mode.
I straced PG backend after running psql:
$ sudo strace -tt -T -v -p $(ps --sort=start_time -elfy | grep "postgres
prod .*startup" | head -n1 | awk '{print $3}')
(...)
08:47:28.870917 read(6, "|\25\3\0\0|\v\335$!\1\0\364\0\20\1\0 \4
\374%\4\6p\237\30\1\340\236\30\1"..., 8192) = 8192 <0.10>
08:47:28.870951 read(6, "|\25\3\0@\274\202\262\254\230\1\0\364\0\20\1\0 \4
\0&\4\6p\237\30\1\340\236\30\1"..., 8192) = 8192 <0.10>
08:47:28.870986 read(6, "|\25\3\0\220\f\270\266\24\t\1\0\364\0\20\1\0 \4
\5&\4\6p\237\30\1\340\236\30\1"..., 8192) = 8192 <0.10>
08:47:28.871021 read(6, "|\25\3\0008%\200\262r%\1\0\364\0\20\1\0 \4
\4&\4\6p\237\30\1\340\236\30\1"..., 8192) = 8192 <0.11>
08:47:28.871056 semop(41779221, [{8, 1, 0}], 1) = 0 <0.10>
08:47:28.871088 read(6, "|\25\3\0\220[\202\262\241\230\1\0\364\0\20\1\0 \4
\6&\4\6p\237\30\1\340\236\30\1"..., 8192) = 8192 <0.10>
08:47:28.871124 read(6, "|\25\3\0\350\247\200\262\32^\1\0\364\0\20\1\0 \4
\1&\4\6p\237\30\1\340\236\30\1"..., 8192) = 8192 <0.10>
08:47:28.871158 read(6, "|\25\3\0P\373\262\266D\262\1\0\364\0\20\1\0 \4
\373%\4\6p\237\30\1\340\236\30\1"..., 8192) = 8192 <0.10>
08:47:28.871192 read(6, "|\25\3\0\360\240\201\262\345\206\1\0\364\0\20\1\0
\4 \3&\4\6p\237\30\1\340\236\30\1"..., 8192) = 8192 <0.10>
08:47:28.871227 read(6, "|\25\3\0p\372\262\266\0h\1\0\364\0\20\1\0 \4
\2&\4\6p\237\30\1\340\236\30\1"..., 8192) = 8192 <0.10>
08:47:28.871262 read(6, "|\25\3\0@\370\262\266\313\267\1\0\364\0\20\1\0 \4
\7&\4\6p\237\30\1\340\236\30\1"..., 8192) = 8192 <0.11>
(...)
then stopped strace and ran:
$ sudo lsof -p $(ps --sort=start_time -elfy | grep "postgres prod
.*startup" | head -n1 | awk '{print $3}')
(...)
postmaste 4722 postgres6u REG8,1 1073741824
369860117 /opt/prod/pg/9.6/base/18370/1108887031
(...)
It's always /opt/prod/pg/9.6/base/18370/1108887031. Unfortunately, no trace
of it in pg_class:
prod=# SELECT relname FROM pg_class WHERE oid = 1108887031;
relname
-
(0 rows)
prod=# SELECT relname FROM pg_class WHERE relfilenode = 1108887031;
relname
-
(0 rows)
What does pg backend do on startup?
I would be thankful for suggestions on how to troubleshoot it.
Versions:
PostgreSQL 9.6.21 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 4.8.5
20150623 (Red Hat 4.8.5-44), 64-bit
Linux 3.10.0-1062.el7.x86_64 #1 SMP Wed Aug 7 18:08:02 UTC 2019 x86_64
x86_64 x86_64 GNU/Linux
--
Thanks,
Marcin
Re: Establishing a local connection to PostgreSQL 9.6 takes seconds
Marcin Barczynski writes: > It's always /opt/prod/pg/9.6/base/18370/1108887031. Unfortunately, no trace > of it in pg_class: It's probably a mapped system catalog, which will have relfilenode = 0. Try SELECT relname FROM pg_class WHERE pg_relation_filenode(oid) = 1108887031; My guess is that whichever catalog it is is badly bloated. regards, tom lane
Re: Establishing a local connection to PostgreSQL 9.6 takes seconds
Thanks for the immediate reply. It turned out to be pg_attribute. It was bloated probably due to the large number of temp tables created. Are there any recommendations on how to prevent such a bloat from happening? On Wed, Jun 16, 2021 at 4:10 PM Tom Lane wrote: > Marcin Barczynski writes: > > It's always /opt/prod/pg/9.6/base/18370/1108887031. Unfortunately, no > trace > > of it in pg_class: > > It's probably a mapped system catalog, which will have relfilenode = 0. > Try > > SELECT relname FROM pg_class WHERE pg_relation_filenode(oid) = 1108887031; > > My guess is that whichever catalog it is is badly bloated. > > regards, tom lane > -- *Marcin Barczyński* | *Senior Software Engineer * | mbarczyn...@starfishstorage.com | http://www.starfishstorage.com
Re: Establishing a local connection to PostgreSQL 9.6 takes seconds
Marcin Barczynski writes: > It turned out to be pg_attribute. It was bloated probably due to the large > number of temp tables created. > Are there any recommendations on how to prevent such a bloat from happening? You could perhaps apply more aggressive autovacuum settings to that catalog. That won't be enough to get rid of the existing problem; you'll likely need to do a VACUUM FULL on it to remove the bloat. But autovac ought to be able to keep up with things in future, if tuned right. My guess is that pg_class has also got a bloat problem, though perhaps not as severe. regards, tom lane
A simple question about text fields
Are there performance issues with the choice of 'text' vs. varchar and some character limit? For instance, if I have a table with ten million records and text fields that may range in length from 15 to 150, can I expect a measurable improvement in response time for using varchar(150) or will textdo just or nearly as well. If the latter is the case, using text across the board is a simpler choice
Re: A simple question about text fields
Martin Mueller writes: > Are there performance issues with the choice of 'text' vs. varchar and some > character limit? For instance, if I have a table with ten million records > and text fields that may range in length from 15 to 150, can I expect a > measurable improvement in response time for using varchar(150) or will text > do just or nearly as well. There is no situation where varchar outperforms text in Postgres. If you need to apply a length constraint for application semantic reasons, do so ... otherwise, text is the native type. It's useful to think of varchar as being a domain over text, though for various reasons it's not implemented quite that way. regards, tom lane
Streaming replication: PANIC on tertiary when secondary promoted
Hi,
I had a cascade serverA->serverB->serverC->serverD of Postgres 10.14
servers connected with streaming replication.
There was no archive shipping set up, but there was an empty directory
/data/pg_archive/10/dedupe_shard1_10/ mentioned in config for it on each
of the servers.
When I promoted serverB, serverC crashed:
Jun 16 14:45:43 serverC postgresql-10-dedupe_shard1_10[43934]: [7-1]
2021-06-16 14:45:43.717 UTC [43934] {-} LOG: replication terminated by
primary server
Jun 16 14:45:43 serverC postgresql-10-dedupe_shard1_10[43934]: [7-2]
2021-06-16 14:45:43.717 UTC [43934] {-} DETAIL: End of WAL reached on
timeline 1 at 190B0/3600.
Jun 16 14:45:43 serverC postgresql-10-dedupe_shard1_10[43934]: [8-1]
2021-06-16 14:45:43.717 UTC [43934] {-} LOG: fetching timeline history
file for timeline 2 from primary server
cp: cannot stat '/data/pg_archive/10/dedupe_shard1_10/0002.history':
No such file or directory
cp: cannot stat '/data/pg_archive/10/dedupe_shard1_10/0003.history':
No such file or directory
cp: cannot stat '/data/pg_archive/10/dedupe_shard1_10/0002.history':
No such file or directory
Jun 16 14:45:43 serverC postgresql-10-dedupe_shard1_10[33222]: [9-1]
2021-06-16 14:45:43.736 UTC [33222] {-} LOG: new target timeline is 2
cp: cannot stat
'/data/pg_archive/10/dedupe_shard1_10/0002000190B00036': No such
file or directory
cp: cannot stat
'/data/pg_archive/10/dedupe_shard1_10/0001000190B00036': No such
file or directory
Jun 16 14:45:43 serverC postgresql-10-dedupe_shard1_10[43934]: [9-1]
2021-06-16 14:45:43.746 UTC [43934] {-} LOG: restarted WAL streaming at
190B0/3600 on timeline 2
Jun 16 14:45:43 serverC postgresql-10-dedupe_shard1_10[43934]: [10-1]
2021-06-16 14:45:43.746 UTC [43934] {-} FATAL: could not receive data
from WAL stream: ERROR: requested starting point 190B0/3600 is
ahead of the WAL flush position of this server 190B0/35E8
cp: cannot stat '/data/pg_archive/10/dedupe_shard1_10/0003.history':
No such file or directory
cp: cannot stat
'/data/pg_archive/10/dedupe_shard1_10/0002000190B00036': No such
file or directory
Jun 16 14:45:43 serverC postgresql-10-dedupe_shard1_10[93365]: [7-1]
2021-06-16 14:45:43.764 UTC [93365] {-} LOG: started streaming WAL from
primary at 190B0/3600 on timeline 2
Jun 16 14:45:43 serverC postgresql-10-dedupe_shard1_10[93365]: [8-1]
2021-06-16 14:45:43.764 UTC [93365] {-} FATAL: could not receive data
from WAL stream: ERROR: requested starting point 190B0/3600 is
ahead of the WAL flush position of this server 190B0/35E8
cp: cannot stat '/data/pg_archive/10/dedupe_shard1_10/0003.history':
No such file or directory
cp: cannot stat
'/data/pg_archive/10/dedupe_shard1_10/0002000190B00036': No such
file or directory
Jun 16 14:45:48 serverC postgresql-10-dedupe_shard1_10[93421]: [7-1]
2021-06-16 14:45:48.771 UTC [93421] {-} LOG: started streaming WAL from
primary at 190B0/3600 on timeline 2
Jun 16 14:45:48 serverC postgresql-10-dedupe_shard1_10[33222]: [10-1]
2021-06-16 14:45:48.792 UTC [33222] {-} LOG: invalid contrecord length
1585 at 190B0/35B8
Jun 16 14:45:48 serverC postgresql-10-dedupe_shard1_10[93421]: [8-1]
2021-06-16 14:45:48.793 UTC [93421] {-} FATAL: terminating walreceiver
process due to administrator command
cp: cannot stat '/data/pg_archive/10/dedupe_shard1_10/0003.history':
No such file or directory
cp: cannot stat
'/data/pg_archive/10/dedupe_shard1_10/0002000190B00035': No such
file or directory
Jun 16 14:45:48 serverC postgresql-10-dedupe_shard1_10[33222]: [11-1]
2021-06-16 14:45:48.803 UTC [33222] {-} PANIC: could not open file
"pg_wal/0002000190B00035": No such file or directory
After I started it it seems to have caught up:
Jun 16 14:59:09 serverB postgresql-10-dedupe_shard1_10[100187]: [8-1]
2021-06-16 14:59:09.826 UTC [100187] {-} LOG: consistent recovery state
reached at 190B0/35B8
Jun 16 14:59:09 serverB postgresql-10-dedupe_shard1_10[100172]: [5-1]
2021-06-16 14:59:09.827 UTC [100172] {-} LOG: database system is ready
to accept read only connections
cp: cannot stat
'/data/pg_archive/10/dedupe_shard1_10/0002000190B00036': No such
file or directory
Jun 16 14:59:10 serverB postgresql-10-dedupe_shard1_10[100187]: [9-1]
2021-06-16 14:59:10.281 UTC [100187] {-} LOG: invalid record length at
190B0/36000898: wanted 24, got 0
Jun 16 14:59:10 serverB postgresql-10-dedupe_shard1_10[101331]: [6-1]
2021-06-16 14:59:10.292 UTC [101331] {-} LOG: started streaming WAL
from primary at 190B0/3600 on timeline 2
Jun 16 14:59:10 serverB postgresql-10-dedupe_shard1_10[101332]: [6-1]
2021-06-16 14:59:10.332 UTC [101332] {[unknown]-[local]}
[unknown]@[unknown] LOG: incomplete startup packet
Jun 16 14:59:10 serverB postgresql-10-dedupe_shard1_10[101334]: [6-1]
2021-06-16 14:59:10.508 UTC [101334] {walreceiver-10.1.10.12(43648)}
replication@[unknown] ERROR: requested star
Re: Streaming replication: PANIC on tertiary when secondary promoted
What is your recovery_target_timeline set to on replicas ?
I just did a primary -> replica -> cascading replica setup. and then
promoted replica as new primary.
cascading replica was working fine, no restarts required.
for me recovery_target_timeline was set to 'latest'
i have pg14beta installed btw.
initdb -D primary
The files belonging to this database system will be owned by user "postgres".
This user must also own the server process.
postgres@db:~/playground$ pg_ctl -D primary -l logfile start
waiting for server to start done
server started
postgres@db:~/playground$ psql
psql (14beta1)
Type "help" for help.
postgres=# select pg_create_physical_replication_slot('replica');
pg_create_physical_replication_slot
-
(replica,)
(1 row)
postgres=# create table t(id int primary key);
CREATE TABLE
postgres=# insert into t select x from generate_series(1, 100) x; checkpoint;
INSERT 0 100
postgres=# \q
-- create a replica
postgres@db:~/playground$ pg_basebackup -D replica -R -X stream -S
replica -v -d "dbname=postgres port=5432" -U postgres
pg_basebackup: initiating base backup, waiting for checkpoint to complete
pg_basebackup: checkpoint completed
pg_basebackup: write-ahead log start point: 0/228 on timeline 1
pg_basebackup: starting background WAL receiver
pg_basebackup: write-ahead log end point: 0/2000138
pg_basebackup: waiting for background process to finish streaming ...
pg_basebackup: syncing data to disk ...
pg_basebackup: renaming backup_manifest.tmp to backup_manifest
pg_basebackup: base backup completed
postgres@db:~/playground$ vim replica/postgresql.conf
--start the replica (port 5433)
postgres@db:~/playground$ pg_ctl -D replica -l replicalog start
waiting for server to start done
server started
postgres@db:~/playground$ psql -p 5433 -c 'select count(1) from t;'
count
---
100
(1 row)
postgres@db:~/playground$ psql -p 5433
psql (14beta1)
Type "help" for help.
-- create a replica slot for cascading streaming replication
postgres=# select pg_create_physical_replication_slot('cascading_replica');
pg_create_physical_replication_slot
-
(cascading_replica,)
(1 row)
postgres=# \q
-- create a cascading replica off replica
postgres@db:~/playground$ pg_basebackup -D cascading_replica -R -X
stream -S cascading_replica -v -d "dbname=postgres port=5433" -U
postgres
pg_basebackup: initiating base backup, waiting for checkpoint to complete
pg_basebackup: checkpoint completed
pg_basebackup: write-ahead log start point: 0/328 on timeline 1
pg_basebackup: starting background WAL receiver
pg_basebackup: write-ahead log end point: 0/3D8
pg_basebackup: waiting for background process to finish streaming ...
pg_basebackup: syncing data to disk ...
pg_basebackup: renaming backup_manifest.tmp to backup_manifest
pg_basebackup: base backup completed
postgres@db:~/playground$ vim cascading_replica/postgresql.conf
postgres@db:~/playground$ pg_ctl -D cascading_replica -l creplica start
waiting for server to start done
server started
-- validate receiving data fine.
postgres@db:~/playground$ psql -p 5434 -c 'select count(1) from t;'
count
---
100
(1 row)
-- stop primary
postgres@db:~/playground$ pg_ctl -D primary -l logfile stop
waiting for server to shut down done
server stopped
-- promote replica to new primary
postgres@db:~/playground$ psql -p 5433
psql (14beta1)
Type "help" for help.
postgres=# select pg_promote();
pg_promote
t
(1 row)
postgres=# select pg_is_in_recovery();
pg_is_in_recovery
---
f
(1 row)
postgres=# \q
--do some dml, validate changes replayed to new replica.
postgres@db:~/playground$ psql -p 5434 -c 'select count(1) from t;'
count
---
100
(1 row)
postgres@db:~/playground$ psql -p 5433 -c 'select count(1) from t;'
count
---
100
(1 row)
postgres@db:~/playground$ psql -p 5433 -c 'delete from t where id < 50;'
DELETE 49
postgres@db:~/playground$ psql -p 5433 -c 'select count(1) from t;'
count
---
51
(1 row)
postgres@db:~/playground$ psql -p 5434 -c 'select count(1) from t;'
count
---
51
(1 row)
in all my cases. recovery_timeline was set to 'latest'.
i did not rx any panic messages in logs.
Re: Streaming replication: PANIC on tertiary when secondary promoted
I had it "latest" as well.
I'll try to reproduce it again tomorrow.
On 16/06/2021 17:20, Vijaykumar Jain wrote:
What is your recovery_target_timeline set to on replicas ?
I just did a primary -> replica -> cascading replica setup. and then
promoted replica as new primary.
cascading replica was working fine, no restarts required.
for me recovery_target_timeline was set to 'latest'
i have pg14beta installed btw.
initdb -D primary
The files belonging to this database system will be owned by user "postgres".
This user must also own the server process.
postgres@db:~/playground$ pg_ctl -D primary -l logfile start
waiting for server to start done
server started
postgres@db:~/playground$ psql
psql (14beta1)
Type "help" for help.
postgres=# select pg_create_physical_replication_slot('replica');
pg_create_physical_replication_slot
-
(replica,)
(1 row)
postgres=# create table t(id int primary key);
CREATE TABLE
postgres=# insert into t select x from generate_series(1, 100) x; checkpoint;
INSERT 0 100
postgres=# \q
-- create a replica
postgres@db:~/playground$ pg_basebackup -D replica -R -X stream -S
replica -v -d "dbname=postgres port=5432" -U postgres
pg_basebackup: initiating base backup, waiting for checkpoint to complete
pg_basebackup: checkpoint completed
pg_basebackup: write-ahead log start point: 0/228 on timeline 1
pg_basebackup: starting background WAL receiver
pg_basebackup: write-ahead log end point: 0/2000138
pg_basebackup: waiting for background process to finish streaming ...
pg_basebackup: syncing data to disk ...
pg_basebackup: renaming backup_manifest.tmp to backup_manifest
pg_basebackup: base backup completed
postgres@db:~/playground$ vim replica/postgresql.conf
--start the replica (port 5433)
postgres@db:~/playground$ pg_ctl -D replica -l replicalog start
waiting for server to start done
server started
postgres@db:~/playground$ psql -p 5433 -c 'select count(1) from t;'
count
---
100
(1 row)
postgres@db:~/playground$ psql -p 5433
psql (14beta1)
Type "help" for help.
-- create a replica slot for cascading streaming replication
postgres=# select pg_create_physical_replication_slot('cascading_replica');
pg_create_physical_replication_slot
-
(cascading_replica,)
(1 row)
postgres=# \q
-- create a cascading replica off replica
postgres@db:~/playground$ pg_basebackup -D cascading_replica -R -X
stream -S cascading_replica -v -d "dbname=postgres port=5433" -U
postgres
pg_basebackup: initiating base backup, waiting for checkpoint to complete
pg_basebackup: checkpoint completed
pg_basebackup: write-ahead log start point: 0/328 on timeline 1
pg_basebackup: starting background WAL receiver
pg_basebackup: write-ahead log end point: 0/3D8
pg_basebackup: waiting for background process to finish streaming ...
pg_basebackup: syncing data to disk ...
pg_basebackup: renaming backup_manifest.tmp to backup_manifest
pg_basebackup: base backup completed
postgres@db:~/playground$ vim cascading_replica/postgresql.conf
postgres@db:~/playground$ pg_ctl -D cascading_replica -l creplica start
waiting for server to start done
server started
-- validate receiving data fine.
postgres@db:~/playground$ psql -p 5434 -c 'select count(1) from t;'
count
---
100
(1 row)
-- stop primary
postgres@db:~/playground$ pg_ctl -D primary -l logfile stop
waiting for server to shut down done
server stopped
-- promote replica to new primary
postgres@db:~/playground$ psql -p 5433
psql (14beta1)
Type "help" for help.
postgres=# select pg_promote();
pg_promote
t
(1 row)
postgres=# select pg_is_in_recovery();
pg_is_in_recovery
---
f
(1 row)
postgres=# \q
--do some dml, validate changes replayed to new replica.
postgres@db:~/playground$ psql -p 5434 -c 'select count(1) from t;'
count
---
100
(1 row)
postgres@db:~/playground$ psql -p 5433 -c 'select count(1) from t;'
count
---
100
(1 row)
postgres@db:~/playground$ psql -p 5433 -c 'delete from t where id < 50;'
DELETE 49
postgres@db:~/playground$ psql -p 5433 -c 'select count(1) from t;'
count
---
51
(1 row)
postgres@db:~/playground$ psql -p 5434 -c 'select count(1) from t;'
count
---
51
(1 row)
in all my cases. recovery_timeline was set to 'latest'.
i did not rx any panic messages in logs.
