Обсуждение: Restoring from PostgreSQL 9.5 dump to 10 is super slow
Hello All,
This is my first and little longer email on this list. I wanted to
share all the information that I have gathered so far and it got
longer.
I am trying to restore database dump created on PostgreSQL 9.5.16 to
PostgreSQL 10.7 and it is taking a lot of time to restore. Restoring
the same dump to 9.5 doesn't take that much. So I am wondering what
could be reason behind this slowness.
Some numbers to show how slow it is:
Small tables (<500MB):
- 9.5 to 9.5 took 1m4.110s
- 9.5 to 10 took 1m4.575s
Medium tables (500MB to 5GB):
- 9.5 to 9.5 took 6m53.132s
- 9.5 to 10 took 6m0.998s
Large tables (5GB+):
- 9.5 to 9.5 took 131m35.106s
- 9.5 to 10 took 831m25.539s
Underlying hardware and OS used in both cases are exactly the same.
Thinking that there could be data format difference between Postgres
9.5 and 10 and that could be the reason to this slowness, I tried
dumping from Postgres 10 and restoring it on Postgres 10, but that is
also super slow.
Here are some numbers of that:
Small tables (<500MB):
- 10 to 10 took 0m51.248s
Medium tables (500MB to 5GB):
- 10 to 10 took 5m40.224s
Large tables (5GB+):
- 10 to 10 took 832m36.850s
Restore commands
The commands I am using to restore:
pg_restore -v -F d -n public -U <user> -d <database> -h localhost -j
4 --disable-triggers -e -L <file with table names>
/var/lib/pgsql/20190425/pg_dump_data
The hardware I am running on:
CPU: Intel(R) Xeon(R) CPU E5-2686 v4 @ 2.30GHz (2 cores)
Memory: 16GB
HDD: nvme 300GB
FS: ext4
Postgres configuration that I have on this setup:
shared_buffers = 128MB
work_mem = 1MB
maintenance_work_mem = 16MB
dynamic_shared_memory_type = posix
huge_pages = try
vacuum_cost_page_hit = 1
vacuum_cost_page_miss = 10
vacuum_cost_page_dirty = 20
bgwriter_lru_maxpages = 100
full_page_writes = on
seq_page_cost = 1.0
random_page_cost = 4.0
wal_level = minimal
wal_sync_method = fsync
wal_log_hints = off
wal_buffers = -1
wal_writer_delay = 200ms
min_wal_size = 1GB
max_wal_size = 80GB
max_wal_senders = 0
wal_keep_segments = 0
wal_sender_timeout = 60s
wal_receiver_status_interval = 10s
wal_receiver_timeout = 60s
autovacuum = on
log_autovacuum_min_duration = -1
autovacuum_max_workers = 3
autovacuum_naptime = 1min
autovacuum_vacuum_threshold = 50
autovacuum_analyze_threshold = 50
autovacuum_vacuum_scale_factor = 0.2
autovacuum_analyze_scale_factor = 0.1
autovacuum_freeze_max_age = 200000000
autovacuum_multixact_freeze_max_age = 400000000
autovacuum_vacuum_cost_delay = 20ms
autovacuum_vacuum_cost_limit = -1
Some more things observed:
* Running strace on Postgres process showed continuous stream of
lseek/read/write calls and it also showed bunch of futex wait and
resume calls. These futex calls are not easily seen on Postgres 9.5
* Looking at pg_stat_activity table showed WALWriteLock under
wait_event column. It used to change but could see this coming up very
frequently.
Thanks,
Siddharth Karandikar
PS: I had posted this on stackoverflow, but didn't get lot of
attention there. So posting it here. Don't know if thats considered
cross-posting. But if thats the case, I would keep that in mind and
avoid it in future.
Hi Siddharth,
The slowness also depends on the data with its type(data type).
Typically it depends based on the amount of ram distributed between other processes and that of pg_restore.
Regards,
Pavan
On Mon, 6 May, 2019, 4:54 PM Siddharth Karandikar, <siddharth.karandikar@gmail.com> wrote:
Hello All,
This is my first and little longer email on this list. I wanted to
share all the information that I have gathered so far and it got
longer.
I am trying to restore database dump created on PostgreSQL 9.5.16 to
PostgreSQL 10.7 and it is taking a lot of time to restore. Restoring
the same dump to 9.5 doesn't take that much. So I am wondering what
could be reason behind this slowness.
Some numbers to show how slow it is:
Small tables (<500MB):
- 9.5 to 9.5 took 1m4.110s
- 9.5 to 10 took 1m4.575s
Medium tables (500MB to 5GB):
- 9.5 to 9.5 took 6m53.132s
- 9.5 to 10 took 6m0.998s
Large tables (5GB+):
- 9.5 to 9.5 took 131m35.106s
- 9.5 to 10 took 831m25.539s
Underlying hardware and OS used in both cases are exactly the same.
Thinking that there could be data format difference between Postgres
9.5 and 10 and that could be the reason to this slowness, I tried
dumping from Postgres 10 and restoring it on Postgres 10, but that is
also super slow.
Here are some numbers of that:
Small tables (<500MB):
- 10 to 10 took 0m51.248s
Medium tables (500MB to 5GB):
- 10 to 10 took 5m40.224s
Large tables (5GB+):
- 10 to 10 took 832m36.850s
Restore commands
The commands I am using to restore:
pg_restore -v -F d -n public -U <user> -d <database> -h localhost -j
4 --disable-triggers -e -L <file with table names>
/var/lib/pgsql/20190425/pg_dump_data
The hardware I am running on:
CPU: Intel(R) Xeon(R) CPU E5-2686 v4 @ 2.30GHz (2 cores)
Memory: 16GB
HDD: nvme 300GB
FS: ext4
Postgres configuration that I have on this setup:
shared_buffers = 128MB
work_mem = 1MB
maintenance_work_mem = 16MB
dynamic_shared_memory_type = posix
huge_pages = try
vacuum_cost_page_hit = 1
vacuum_cost_page_miss = 10
vacuum_cost_page_dirty = 20
bgwriter_lru_maxpages = 100
full_page_writes = on
seq_page_cost = 1.0
random_page_cost = 4.0
wal_level = minimal
wal_sync_method = fsync
wal_log_hints = off
wal_buffers = -1
wal_writer_delay = 200ms
min_wal_size = 1GB
max_wal_size = 80GB
max_wal_senders = 0
wal_keep_segments = 0
wal_sender_timeout = 60s
wal_receiver_status_interval = 10s
wal_receiver_timeout = 60s
autovacuum = on
log_autovacuum_min_duration = -1
autovacuum_max_workers = 3
autovacuum_naptime = 1min
autovacuum_vacuum_threshold = 50
autovacuum_analyze_threshold = 50
autovacuum_vacuum_scale_factor = 0.2
autovacuum_analyze_scale_factor = 0.1
autovacuum_freeze_max_age = 200000000
autovacuum_multixact_freeze_max_age = 400000000
autovacuum_vacuum_cost_delay = 20ms
autovacuum_vacuum_cost_limit = -1
Some more things observed:
* Running strace on Postgres process showed continuous stream of
lseek/read/write calls and it also showed bunch of futex wait and
resume calls. These futex calls are not easily seen on Postgres 9.5
* Looking at pg_stat_activity table showed WALWriteLock under
wait_event column. It used to change but could see this coming up very
frequently.
Thanks,
Siddharth Karandikar
PS: I had posted this on stackoverflow, but didn't get lot of
attention there. So posting it here. Don't know if thats considered
cross-posting. But if thats the case, I would keep that in mind and
avoid it in future.
Pavan, On Mon, May 6, 2019 at 4:58 PM Pavan Teja <pavan.postgresdba@gmail.com> wrote: > > Hi Siddharth, > > The slowness also depends on the data with its type(data type). 9.5 to 9.5 works well so are you pointing to specific datatypes I should be looking for that changed from 9.5 to 10? > > Typically it depends based on the amount of ram distributed between other processes and that of pg_restore. > pg_restore was the main activity running on that machine. It was allowed to take whole memory - if needed. And I think it does take almost all the memory. > Regards, > Pavan > > On Mon, 6 May, 2019, 4:54 PM Siddharth Karandikar, <siddharth.karandikar@gmail.com> wrote: >> >> Hello All, >> >> This is my first and little longer email on this list. I wanted to >> share all the information that I have gathered so far and it got >> longer. >> >> I am trying to restore database dump created on PostgreSQL 9.5.16 to >> PostgreSQL 10.7 and it is taking a lot of time to restore. Restoring >> the same dump to 9.5 doesn't take that much. So I am wondering what >> could be reason behind this slowness. >> >> Some numbers to show how slow it is: >> >> Small tables (<500MB): >> - 9.5 to 9.5 took 1m4.110s >> - 9.5 to 10 took 1m4.575s >> Medium tables (500MB to 5GB): >> - 9.5 to 9.5 took 6m53.132s >> - 9.5 to 10 took 6m0.998s >> Large tables (5GB+): >> - 9.5 to 9.5 took 131m35.106s >> - 9.5 to 10 took 831m25.539s >> >> Underlying hardware and OS used in both cases are exactly the same. >> Thinking that there could be data format difference between Postgres >> 9.5 and 10 and that could be the reason to this slowness, I tried >> dumping from Postgres 10 and restoring it on Postgres 10, but that is >> also super slow. >> >> Here are some numbers of that: >> >> Small tables (<500MB): >> - 10 to 10 took 0m51.248s >> Medium tables (500MB to 5GB): >> - 10 to 10 took 5m40.224s >> Large tables (5GB+): >> - 10 to 10 took 832m36.850s >> >> Restore commands >> The commands I am using to restore: >> pg_restore -v -F d -n public -U <user> -d <database> -h localhost -j >> 4 --disable-triggers -e -L <file with table names> >> /var/lib/pgsql/20190425/pg_dump_data >> >> The hardware I am running on: >> CPU: Intel(R) Xeon(R) CPU E5-2686 v4 @ 2.30GHz (2 cores) >> Memory: 16GB >> HDD: nvme 300GB >> FS: ext4 >> >> Postgres configuration that I have on this setup: >> shared_buffers = 128MB >> >> work_mem = 1MB >> maintenance_work_mem = 16MB >> dynamic_shared_memory_type = posix >> >> huge_pages = try >> vacuum_cost_page_hit = 1 >> vacuum_cost_page_miss = 10 >> vacuum_cost_page_dirty = 20 >> bgwriter_lru_maxpages = 100 >> full_page_writes = on >> seq_page_cost = 1.0 >> random_page_cost = 4.0 >> >> wal_level = minimal >> wal_sync_method = fsync >> wal_log_hints = off >> wal_buffers = -1 >> wal_writer_delay = 200ms >> min_wal_size = 1GB >> max_wal_size = 80GB >> max_wal_senders = 0 >> wal_keep_segments = 0 >> wal_sender_timeout = 60s >> wal_receiver_status_interval = 10s >> wal_receiver_timeout = 60s >> >> autovacuum = on >> log_autovacuum_min_duration = -1 >> autovacuum_max_workers = 3 >> autovacuum_naptime = 1min >> autovacuum_vacuum_threshold = 50 >> autovacuum_analyze_threshold = 50 >> autovacuum_vacuum_scale_factor = 0.2 >> autovacuum_analyze_scale_factor = 0.1 >> autovacuum_freeze_max_age = 200000000 >> autovacuum_multixact_freeze_max_age = 400000000 >> autovacuum_vacuum_cost_delay = 20ms >> autovacuum_vacuum_cost_limit = -1 >> >> >> Some more things observed: >> * Running strace on Postgres process showed continuous stream of >> lseek/read/write calls and it also showed bunch of futex wait and >> resume calls. These futex calls are not easily seen on Postgres 9.5 >> * Looking at pg_stat_activity table showed WALWriteLock under >> wait_event column. It used to change but could see this coming up very >> frequently. >> >> >> Thanks, >> Siddharth Karandikar >> >> PS: I had posted this on stackoverflow, but didn't get lot of >> attention there. So posting it here. Don't know if thats considered >> cross-posting. But if thats the case, I would keep that in mind and >> avoid it in future. >> >>
Hi, On 2019-05-06 16:54:08 +0530, Siddharth Karandikar wrote: > I am trying to restore database dump created on PostgreSQL 9.5.16 to > PostgreSQL 10.7 and it is taking a lot of time to restore. Restoring > the same dump to 9.5 doesn't take that much. So I am wondering what > could be reason behind this slowness. Is there any chance the configuration is different between 9.5 and 10? If there e.g. is an index on the table, the maintanance_work_mem setting would make a large differerence when rebuilding. Note that the medium-tablecase is noticably faster in 10 and that there's been some speedup work around that in 10. > > Postgres configuration that I have on this setup: > shared_buffers = 128MB > > work_mem = 1MB > maintenance_work_mem = 16MB maintenance_work_mem = 16Mb is a very low value - it's e.g. used for index builds, to sort the data. Greetings, Andres Freund
Hi Andres, On Mon, May 6, 2019 at 8:09 PM Andres Freund <andres@anarazel.de> wrote: > > Hi, > > On 2019-05-06 16:54:08 +0530, Siddharth Karandikar wrote: > > I am trying to restore database dump created on PostgreSQL 9.5.16 to > > PostgreSQL 10.7 and it is taking a lot of time to restore. Restoring > > the same dump to 9.5 doesn't take that much. So I am wondering what > > could be reason behind this slowness. > > Is there any chance the configuration is different between 9.5 and 10? I double checked, but there is no difference in configurations of 9.5 and 10. 9.5 restore works fine with maintenance_work_mem set to 16MB. But I will rerun restore on 10 with higher maintenance_work_mem. > If there e.g. is an index on the table, the maintanance_work_mem setting > would make a large differerence when rebuilding. Note that the > medium-tablecase is noticably faster in 10 and that there's been some > speedup work around that in 10. > > > > > Postgres configuration that I have on this setup: > > shared_buffers = 128MB > > > > work_mem = 1MB > > maintenance_work_mem = 16MB > > maintenance_work_mem = 16Mb is a very low value - it's e.g. used for > index builds, to sort the data. > > Greetings, > > Andres Freund
Tried restoring to pg10 with maintenance_work_mem=1GB. No change in runtime. When tried same on pg9.5 it ran couple of minutes faster than previous run. Now I am going to turn off autovacuum and see if that makes any difference. On Tue, May 7, 2019 at 10:38 AM Siddharth Karandikar <siddharth.karandikar@gmail.com> wrote: > > Hi Andres, > > On Mon, May 6, 2019 at 8:09 PM Andres Freund <andres@anarazel.de> wrote: > > > > Hi, > > > > On 2019-05-06 16:54:08 +0530, Siddharth Karandikar wrote: > > > I am trying to restore database dump created on PostgreSQL 9.5.16 to > > > PostgreSQL 10.7 and it is taking a lot of time to restore. Restoring > > > the same dump to 9.5 doesn't take that much. So I am wondering what > > > could be reason behind this slowness. > > > > Is there any chance the configuration is different between 9.5 and 10? > I double checked, but there is no difference in configurations of 9.5 > and 10. 9.5 restore works fine > with maintenance_work_mem set to 16MB. > > But I will rerun restore on 10 with higher maintenance_work_mem. > > > If there e.g. is an index on the table, the maintanance_work_mem setting > > would make a large differerence when rebuilding. Note that the > > medium-tablecase is noticably faster in 10 and that there's been some > > speedup work around that in 10. > > > > > > > > Postgres configuration that I have on this setup: > > > shared_buffers = 128MB > > > > > > work_mem = 1MB > > > maintenance_work_mem = 16MB > > > > maintenance_work_mem = 16Mb is a very low value - it's e.g. used for > > index builds, to sort the data. > > > > Greetings, > > > > Andres Freund
Hi, Another thing that I want to bring up is, whenever I do `select * from pg_stat_activity;` Lot of times I see LWLock and WALWriteLock for wait_event_type and wait_event respectively on all 4 restore `COPY` jobs. I would like to understand what exactly it is trying to indicate. Could this be reason behind slow restores? On Tue, May 7, 2019 at 2:29 PM Siddharth Karandikar <siddharth.karandikar@gmail.com> wrote: > > Tried restoring to pg10 with maintenance_work_mem=1GB. No change in runtime. > When tried same on pg9.5 it ran couple of minutes faster than previous run. > > Now I am going to turn off autovacuum and see if that makes any difference. > > On Tue, May 7, 2019 at 10:38 AM Siddharth Karandikar > <siddharth.karandikar@gmail.com> wrote: > > > > Hi Andres, > > > > On Mon, May 6, 2019 at 8:09 PM Andres Freund <andres@anarazel.de> wrote: > > > > > > Hi, > > > > > > On 2019-05-06 16:54:08 +0530, Siddharth Karandikar wrote: > > > > I am trying to restore database dump created on PostgreSQL 9.5.16 to > > > > PostgreSQL 10.7 and it is taking a lot of time to restore. Restoring > > > > the same dump to 9.5 doesn't take that much. So I am wondering what > > > > could be reason behind this slowness. > > > > > > Is there any chance the configuration is different between 9.5 and 10? > > I double checked, but there is no difference in configurations of 9.5 > > and 10. 9.5 restore works fine > > with maintenance_work_mem set to 16MB. > > > > But I will rerun restore on 10 with higher maintenance_work_mem. > > > > > If there e.g. is an index on the table, the maintanance_work_mem setting > > > would make a large differerence when rebuilding. Note that the > > > medium-tablecase is noticably faster in 10 and that there's been some > > > speedup work around that in 10. > > > > > > > > > > > Postgres configuration that I have on this setup: > > > > shared_buffers = 128MB > > > > > > > > work_mem = 1MB > > > > maintenance_work_mem = 16MB > > > > > > maintenance_work_mem = 16Mb is a very low value - it's e.g. used for > > > index builds, to sort the data. > > > > > > Greetings, > > > > > > Andres Freund
Hello all, Researching more on reasons why WALWriteLock is observed so frequently - increasing wal_buffers made perfect sense. But before reaching there I had done following config changes - maintenance_work_mem 1GB - autovacuum off - synchronous_commit off - shared_buffers=4GB And finally I explicitly set wal_buffers = 128MB becasue with -1 it was calculating it to be just 16MB. With above configurations, pg9.5 dump of large tables could be restored on pg10 in just `94m31.869s` - this is huge improvement compared to 831m25.539s that I was getting before. Yay!! Still not sure why it just worked on to restore on pg9.5 without any of these config changes. And also not sure if this is the best performance that one can get. Will making wal_buffers 512MB improve it? - so more inputs/suggestions are welcome. :) But feeling better for now. Btw, these are the references which I went through. http://rhaas.blogspot.com/2019/01/how-much-maintenanceworkmem-do-i-need.html http://www.databasesoup.com/2014/09/settings-for-fast-pgrestore.html https://docs.aws.amazon.com/AmazonRDS/latest/UserGuide/PostgreSQL.Procedural.Importing.html https://tech.lendinghome.com/practical-guide-to-postgresql-optimizations-d7b9c2ad6a22 https://www.postgresql.org/message-id/CA+Tgmoav9Q5v5ZGT3+wP_1tQjT6TGYXrwrDcTRrWimC+ZY7RRA@mail.gmail.com https://www.postgresql.org/docs/10/monitoring-stats.html On Tue, May 7, 2019 at 2:44 PM Siddharth Karandikar <siddharth.karandikar@gmail.com> wrote: > > Hi, > > Another thing that I want to bring up is, whenever I do `select * from > pg_stat_activity;` > Lot of times I see LWLock and WALWriteLock for wait_event_type and > wait_event respectively > on all 4 restore `COPY` jobs. > > I would like to understand what exactly it is trying to indicate. > Could this be reason > behind slow restores? > > On Tue, May 7, 2019 at 2:29 PM Siddharth Karandikar > <siddharth.karandikar@gmail.com> wrote: > > > > Tried restoring to pg10 with maintenance_work_mem=1GB. No change in runtime. > > When tried same on pg9.5 it ran couple of minutes faster than previous run. > > > > Now I am going to turn off autovacuum and see if that makes any difference. > > > > On Tue, May 7, 2019 at 10:38 AM Siddharth Karandikar > > <siddharth.karandikar@gmail.com> wrote: > > > > > > Hi Andres, > > > > > > On Mon, May 6, 2019 at 8:09 PM Andres Freund <andres@anarazel.de> wrote: > > > > > > > > Hi, > > > > > > > > On 2019-05-06 16:54:08 +0530, Siddharth Karandikar wrote: > > > > > I am trying to restore database dump created on PostgreSQL 9.5.16 to > > > > > PostgreSQL 10.7 and it is taking a lot of time to restore. Restoring > > > > > the same dump to 9.5 doesn't take that much. So I am wondering what > > > > > could be reason behind this slowness. > > > > > > > > Is there any chance the configuration is different between 9.5 and 10? > > > I double checked, but there is no difference in configurations of 9.5 > > > and 10. 9.5 restore works fine > > > with maintenance_work_mem set to 16MB. > > > > > > But I will rerun restore on 10 with higher maintenance_work_mem. > > > > > > > If there e.g. is an index on the table, the maintanance_work_mem setting > > > > would make a large differerence when rebuilding. Note that the > > > > medium-tablecase is noticably faster in 10 and that there's been some > > > > speedup work around that in 10. > > > > > > > > > > > > > > Postgres configuration that I have on this setup: > > > > > shared_buffers = 128MB > > > > > > > > > > work_mem = 1MB > > > > > maintenance_work_mem = 16MB > > > > > > > > maintenance_work_mem = 16Mb is a very low value - it's e.g. used for > > > > index builds, to sort the data. > > > > > > > > Greetings, > > > > > > > > Andres Freund
Hi, On 2019-05-07 18:04:04 +0530, Siddharth Karandikar wrote: > But before reaching there I had done following config changes > - maintenance_work_mem 1GB > - autovacuum off unlikely to matter for a bulk load. > - synchronous_commit off unlikely to matter for a bulk load. > - shared_buffers=4GB > > And finally I explicitly set wal_buffers = 128MB becasue with -1 it > was calculating it to be just 16MB. > > With above configurations, pg9.5 dump of large tables could be > restored on pg10 in just `94m31.869s` - this is huge improvement > compared to 831m25.539s that I was getting before. > Yay!! > > Still not sure why it just worked on to restore on pg9.5 without any > of these config changes. Ah, I bet the wal_level is different in the two clusters. The default in 9.5 wasn't usable for replication and hot backups. But the newer one also has increased overhead in precisely one case - when loading data into a new table. Try setting wal_level = minimal in 10. > And also not sure if this is the best performance that one can get. > Will making wal_buffers 512MB improve it? Extremely unlikely. Regards, Andres
You are absolutely right Andres. I tested restore by keeping synchronous_commit and autovacuum ON. No performance degradation. On Tue, May 7, 2019 at 9:14 PM Andres Freund <andres@anarazel.de> wrote: > > Hi, > > On 2019-05-07 18:04:04 +0530, Siddharth Karandikar wrote: > > But before reaching there I had done following config changes > > - maintenance_work_mem 1GB > > - autovacuum off > > unlikely to matter for a bulk load. > > > > - synchronous_commit off > > unlikely to matter for a bulk load. > > > > - shared_buffers=4GB > > > > And finally I explicitly set wal_buffers = 128MB becasue with -1 it > > was calculating it to be just 16MB. > > > > With above configurations, pg9.5 dump of large tables could be > > restored on pg10 in just `94m31.869s` - this is huge improvement > > compared to 831m25.539s that I was getting before. > > Yay!! > > > > Still not sure why it just worked on to restore on pg9.5 without any > > of these config changes. > > Ah, I bet the wal_level is different in the two clusters. The default in > 9.5 wasn't usable for replication and hot backups. But the newer one > also has increased overhead in precisely one case - when loading data > into a new table. Try setting wal_level = minimal in 10. > > > > And also not sure if this is the best performance that one can get. > > Will making wal_buffers 512MB improve it? > > Extremely unlikely. > > Regards, > > Andres