pg.ddx.io pgsql-admin@postgresql.org mailing list archive
help / color / mirror / Atom feedVery long standby database startup after doing pg_basebackup
4+ messages / 2 participants
[nested] [flat]
* Very long standby database startup after doing pg_basebackup
@ 2018-03-21 12:55 Mario Mahovlić <mariomahovlic@gmail.com>
2018-03-22 07:55 ` Re: Very long standby database startup after doing pg_basebackup Laurenz Albe <laurenz.albe@cybertec.at>
0 siblings, 1 reply; 4+ messages in thread
From: Mario Mahovlić @ 2018-03-21 12:55 UTC (permalink / raw)
To: pgsql-admin@lists.postgresql.org
Hello,
We are running 2 nodes (primary and standby) of PostgreSQL 9.6 with
asynchronous streaming replication set up.
We use repmgr 3.3.2 for managing replication/failover, and we are
experiencing long database startup after cloning the primary node.
We use repmgrs standby clone command and it executes pg_basebackup as
follows:
INFO: executing: '/usr/lib/postgresql/9.6/bin/pg_basebackup -l "repmgr base
backup" -D /var/lib/postgresql/data -h *NODE_IP* -p *PORT* -U *USER* -c
fast -X stream '
However, our issue is not with primary cloning, but with database startup
after clone/basebackup is done.
Startup of standby database is successful but it takes around 6 hours,
during which time all we get from DB is: FATAL: the database system is
starting up.
We have noticed that this startup process uses only 1 cpu core on our
machine which has 8.
Our database size is around 570GB, and we are using schema per tenant data
distribution, so we have separate schemas for each of the users of our
application, as it suits our needs well.
Because of this our database has about 40000 schemas with 5 tables per each
schema.
We suspect the reason behind this long startup is amount of data and/or
large number of schemas/tables on database, however we would like to
confirm that somehow.
So our questions are following:
- What could be possible reasons for startup as long as this?
- How can we figure out what exactly does postgres startup process do
all this time, is there any documentation on what exactly does postgres
database do on startup as we have not found any info on this?
- Is there any way to speed up this startup process?
- Can we mitigate this startup time in cases when we do planned
switchover for maintenance by using pg_rewind instead of pulling all data
from primary again? So if we shut down the database gracefully and use
pg_rewind will startup process be faster?
Thanks in advance for any help you might provide, kind regards.
^ permalink raw reply [nested|flat] 4+ messages in thread
* Re: Very long standby database startup after doing pg_basebackup
2018-03-21 12:55 Very long standby database startup after doing pg_basebackup Mario Mahovlić <mariomahovlic@gmail.com>
@ 2018-03-22 07:55 ` Laurenz Albe <laurenz.albe@cybertec.at>
2018-03-23 09:07 ` Re: Very long standby database startup after doing pg_basebackup Mario Mahovlić <mariomahovlic@gmail.com>
0 siblings, 1 reply; 4+ messages in thread
From: Laurenz Albe @ 2018-03-22 07:55 UTC (permalink / raw)
To: Mario Mahovlić <mariomahovlic@gmail.com>; pgsql-admin@lists.postgresql.org
Mario Mahovlić wrote:
> However, our issue is not with primary cloning, but with database startup after
> clone/basebackup is done.
> Startup of standby database is successful but it takes around 6 hours, during
> which time all we get from DB is: FATAL: the database system is starting up.
> We have noticed that this startup process uses only 1 cpu core on our machine
> which has 8.
>
> Our database size is around 570GB, and we are using schema per tenant data
> distribution, so we have separate schemas for each of the users of our
> application, as it suits our needs well.
> Because of this our database has about 40000 schemas with 5 tables per each
> schema.
> We suspect the reason behind this long startup is amount of data and/or large
> number of schemas/tables on database, however we would like to confirm that somehow.
>
> So our questions are following:
> What could be possible reasons for startup as long as this?
> How can we figure out what exactly does postgres startup process do all this time,
> is there any documentation on what exactly does postgres database do on startup as
> we have not found any info on this?
> Is there any way to speed up this startup process?
> Can we mitigate this startup time in cases when we do planned switchover for
> maintenance by using pg_rewind instead of pulling all data from primary again?
> So if we shut down the database gracefully and use pg_rewind will startup process
> be faster?
You could use "perf top" to see where the time is spent or have
a look at the PostgeSQL log file.
pg_basebackup creates a checkpoint when it starts, so checkpoints that happen
too rarely cannot be the problem.
Did you use "pg_basebackup -X stream" to copy the WAL files along with the data?
If yes, is there a lot of them?
If no, how do you restore the required WAL files?
Yours,
Laurenz Albe
--
Cybertec | https://www.cybertec-postgresql.com
^ permalink raw reply [nested|flat] 4+ messages in thread
* Re: Very long standby database startup after doing pg_basebackup
2018-03-21 12:55 Very long standby database startup after doing pg_basebackup Mario Mahovlić <mariomahovlic@gmail.com>
2018-03-22 07:55 ` Re: Very long standby database startup after doing pg_basebackup Laurenz Albe <laurenz.albe@cybertec.at>
@ 2018-03-23 09:07 ` Mario Mahovlić <mariomahovlic@gmail.com>
2018-03-23 09:42 ` Re: Very long standby database startup after doing pg_basebackup Laurenz Albe <laurenz.albe@cybertec.at>
0 siblings, 1 reply; 4+ messages in thread
From: Mario Mahovlić @ 2018-03-23 09:07 UTC (permalink / raw)
To: Laurenz Albe <laurenz.albe@cybertec.at>; +Cc: pgsql-admin@lists.postgresql.org
Hello Laurenz,
Thank you for the reply, we will try using perf to see what exactly is
going on.
As for the log file all we get from it (even when log level is set to
debug5) is this:
>>> Starting postgres...
> LOG: database system was interrupted; last known up at 2018-03-20
> 08:25:18 UTC
> FATAL: the database system is starting up
> psql: FATAL: the database system is starting up
> >>> Db replication is still not accessible on *NODE* (trying 17255 times)
>
*..... * This goes on for 6 hours * *
LOG: entering standby mode
> LOG: redo starts at 4B/A000028
> LOG: consistent recovery state reached at 4B/A000130
> LOG: database system is ready to accept read only connections
> LOG: started streaming WAL from primary at 4B/B000000 on timeline 35
> DEBUG: CommitTransaction
> DEBUG: name: unnamed; blockState: STARTED; state: INPROGR,
> xid/subid/cid: 0/1/0, nestlvl: 1, children:
> DEBUG: StartTransactionCommand
> DEBUG: StartTransaction
...
Lines with >>> are from our own scripts we use for startup and database
management.
So basically on startup all we get in logs is:
LOG: database system was interrupted; last known up at 2018-03-20 08:25:18
UTC
FATAL: the database system is starting up -> every time we query db until
it starts up successfully
Is there any other way to log more detail during postgres startup?
As i said in initial mail we use -X stream option when doing
pg_basebackup, here is exact pg_basebackup command that is being run:
INFO: executing: '/usr/lib/postgresql/9.6/bin/pg_basebackup -l "repmgr base
> backup" -D /var/lib/postgresql/data -h *NODE_IP* -p *PORT* -U *USER* -c
> fast -X stream '
So yes, we do copy the WAL files, and there is at most 30GB of them (that
is how much we keep), however even if database had to restore all of them 6
hours seems a bit much.
Thank you for the help, kind regards.
On 22 March 2018 at 08:55, Laurenz Albe <laurenz.albe@cybertec.at> wrote:
> Mario Mahovlić wrote:
> > However, our issue is not with primary cloning, but with database
> startup after
> > clone/basebackup is done.
> > Startup of standby database is successful but it takes around 6 hours,
> during
> > which time all we get from DB is: FATAL: the database system is
> starting up.
> > We have noticed that this startup process uses only 1 cpu core on our
> machine
> > which has 8.
> >
> > Our database size is around 570GB, and we are using schema per tenant
> data
> > distribution, so we have separate schemas for each of the users of our
> > application, as it suits our needs well.
> > Because of this our database has about 40000 schemas with 5 tables per
> each
> > schema.
> > We suspect the reason behind this long startup is amount of data and/or
> large
> > number of schemas/tables on database, however we would like to confirm
> that somehow.
> >
> > So our questions are following:
> > What could be possible reasons for startup as long as this?
> > How can we figure out what exactly does postgres startup process do all
> this time,
> > is there any documentation on what exactly does postgres database do on
> startup as
> > we have not found any info on this?
> > Is there any way to speed up this startup process?
> > Can we mitigate this startup time in cases when we do planned switchover
> for
> > maintenance by using pg_rewind instead of pulling all data from primary
> again?
> > So if we shut down the database gracefully and use pg_rewind will
> startup process
> > be faster?
>
> You could use "perf top" to see where the time is spent or have
> a look at the PostgeSQL log file.
>
> pg_basebackup creates a checkpoint when it starts, so checkpoints that
> happen
> too rarely cannot be the problem.
>
> Did you use "pg_basebackup -X stream" to copy the WAL files along with the
> data?
> If yes, is there a lot of them?
> If no, how do you restore the required WAL files?
>
> Yours,
> Laurenz Albe
> --
> Cybertec | https://www.cybertec-postgresql.com
>
^ permalink raw reply [nested|flat] 4+ messages in thread
* Re: Very long standby database startup after doing pg_basebackup
2018-03-21 12:55 Very long standby database startup after doing pg_basebackup Mario Mahovlić <mariomahovlic@gmail.com>
2018-03-22 07:55 ` Re: Very long standby database startup after doing pg_basebackup Laurenz Albe <laurenz.albe@cybertec.at>
2018-03-23 09:07 ` Re: Very long standby database startup after doing pg_basebackup Mario Mahovlić <mariomahovlic@gmail.com>
@ 2018-03-23 09:42 ` Laurenz Albe <laurenz.albe@cybertec.at>
0 siblings, 0 replies; 4+ messages in thread
From: Laurenz Albe @ 2018-03-23 09:42 UTC (permalink / raw)
To: Mario Mahovlić <mariomahovlic@gmail.com>; +Cc: pgsql-admin@lists.postgresql.org
Mario Mahovlić wrote:
> Thank you for the reply, we will try using perf to see what exactly is going on.
> As for the log file all we get from it (even when log level is set to debug5) is this:
>
> > >>> Starting postgres...
> > LOG: database system was interrupted; last known up at 2018-03-20 08:25:18 UTC
> > FATAL: the database system is starting up
> > psql: FATAL: the database system is starting up
> > >>> Db replication is still not accessible on *NODE* (trying 17255 times)
> > ..... * This goes on for 6 hours *
> > LOG: entering standby mode
> > LOG: redo starts at 4B/A000028
> > LOG: consistent recovery state reached at 4B/A000130
> > LOG: database system is ready to accept read only connections
> > LOG: started streaming WAL from primary at 4B/B000000 on timeline 35
> > DEBUG: CommitTransaction
> > DEBUG: name: unnamed; blockState: STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> > DEBUG: StartTransactionCommand
> > DEBUG: StartTransaction
> > ...
>
> Lines with >>> are from our own scripts we use for startup and database management.
>
> So basically on startup all we get in logs is:
> LOG: database system was interrupted; last known up at 2018-03-20 08:25:18 UTC
> FATAL: the database system is starting up -> every time we query db until it starts up successfully
>
> Is there any other way to log more detail during postgres startup?
>
> As i said in initial mail we use -X stream option when doing pg_basebackup, here is exact pg_basebackup command that is being run:
>
> > INFO: executing: '/usr/lib/postgresql/9.6/bin/pg_basebackup -l "repmgr base backup" -D /var/lib/postgresql/data -h *NODE_IP* -p *PORT* -U *USER* -c fast -X stream '
>
> So yes, we do copy the WAL files, and there is at most 30GB of them (that is how much we keep), however even if database had to restore all of them 6 hours seems a bit much.
Sorry, I missed the pg_basebackup command.
The strange thing is that you see the message "entering standby mode" only six
hours after startup. This message is written when recovery *starts*, so
(as expected) it is not that recovery takes long.
By the way, you should add %m to your log_line_prefix so we see *when* messages
are logged.
^ permalink raw reply [nested|flat] 4+ messages in thread
end of thread, other threads:[~2018-03-23 09:42 UTC | newest]
Thread overview: 4+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2018-03-21 12:55 Very long standby database startup after doing pg_basebackup Mario Mahovlić <mariomahovlic@gmail.com>
2018-03-22 07:55 ` Laurenz Albe <laurenz.albe@cybertec.at>
2018-03-23 09:07 ` Mario Mahovlić <mariomahovlic@gmail.com>
2018-03-23 09:42 ` Laurenz Albe <laurenz.albe@cybertec.at>
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