On Tue, Nov 16, 2021 at 04:43:25AM +0000, Robert Creager wrote: > We’re executing the following copy to fill a table with approximately 5k > records, then repeating for a total of 250k records. Normally, this copy > executes < 1 second, with the entire set taking a couple of minutes. The > problem is not reproducible on command, but usually within a couple of hours > of starting some test runs. > > COPY ds3.blob (byte_offset, checksum, checksum_type, id, length, object_id) > FROM STDIN WITH DELIMITER AS ‘|’ > > But, occasionally we get into a huge performance bottleneck for about 2 > hours, where these copy operations are taking 140 seconds or so > > Nov 15 22:25:49 sm4u-34 postgres[5799]: [381-1] > db=tapesystem,user=Administrator,app=PostgreSQL JDBC Driver,client=127.0.0.1 > LOG: duration: 145326.293 ms statement: COPY ds3.blob (byte_offset, > checksum, checksum_type, id, length, object_id) FROM STDIN WITH DELIMITER AS > '|'
> I’m logging statements with pgbadger monitoring the logs. There are no > apparent auto-vacuum’s running, nor any vacuums, nor anything at all really. > Other select queries around that time frame are executing normally. What about checkpoints ? Would you show the "^checkpoint starting" and "^checkpoint complete" logs surrounding a slow COPY ? > We’re coming from PostgreSQL 9.6 on FreeBSD 11 where we did not see this > problem, but have a major release upgrade happening. I’m checking to see if > this machine was updated or was a fresh install. > PostgreSQL 13.2 on amd64-portbld-freebsd13.0, compiled by FreeBSD clang > version 11.0.1 (g...@github.com<mailto:g...@github.com>:llvm/llvm-project.git > llvmorg-11.0.1-0-g43ff75f2c3fe), 64-bit > > Changes made to the settings in the postgresql.conf file > checkpoint_timeout | 30min | > configuration file > log_checkpoints | on | > configuration file > log_lock_waits | on | > configuration file ... > shared_buffers | 21679MB | > configuration file > Operating system and version: > FreeBSD sm4u-34 13.0-STABLE FreeBSD 13.0-STABLE #0: Mon Sep 13 10:11:57 MDT > 2021 > These are the system calls made over 30 seconds from Postgres during a > slowdown. ... > fsync 27 -- Justin
