Hello all,
A description of what you are trying to achieve and what results you expect.: 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 '|'
One CPU is pegged, the data has been sent over STDIN, so Postgres is not waiting for more, there are no other queries running using this select:
SELECT pid,
client_port, now() - query_start AS "runtime", query_start, datname, state, wait_event_type, query, usename FROM pg_stat_activity WHERE query !~ 'pg_stat_activity' AND state != 'idle' ORDER BY state, runtime DESC; # pid,client_port,runtime,query_start,datname,state,wait_event_type,query,usename
5799,27136,0 years 0 mons 0 days 0 hours 2 mins 15.534339 secs,2021-11-15 22:23:23.932988 +00:00,tapesystem,active,,"COPY ds3.blob (byte_offset, checksum, checksum_type, id, length, object_id) FROM STDIN WITH DELIMITER AS '|'",Administrator
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.
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.
From pbgadger:
PostgreSQL version number you are running:
PostgreSQL 13.2 on amd64-portbld-freebsd13.0, compiled by FreeBSD clang version 11.0.1 (git@xxxxxxxxxx:llvm/llvm-project.git llvmorg-11.0.1-0-g43ff75f2c3fe),
64-bit
How you installed PostgreSQL: Ports tree, compiled from source.
Changes made to the settings in the postgresql.conf file
name | current_setting | source
---------------------------------+---------------------------------+--------------------
application_name | psql | client
autovacuum_analyze_scale_factor | 0.05 | configuration file
autovacuum_analyze_threshold | 5000 | configuration file
autovacuum_max_workers | 8 | configuration file
autovacuum_vacuum_cost_delay | 5ms | configuration file
autovacuum_vacuum_scale_factor | 0.1 | configuration file
autovacuum_vacuum_threshold | 5000 | configuration file
checkpoint_completion_target | 0.9 | configuration file
checkpoint_timeout | 30min | configuration file
checkpoint_warning | 5min | configuration file
client_encoding | UTF8 | client
commit_delay | 1000 | configuration file
DateStyle | ISO, MDY | configuration file
default_text_search_config | pg_catalog.english | configuration file
dynamic_shared_memory_type | posix | configuration file
effective_cache_size | 58076MB | configuration file
effective_io_concurrency | 200 | configuration file
full_page_writes | off | configuration file
hot_standby | off | configuration file
lc_messages | C | configuration file
lc_monetary | C | configuration file
lc_numeric | C | configuration file
lc_time | C | configuration file
listen_addresses | * | configuration file
log_autovacuum_min_duration | 1s | configuration file
log_checkpoints | on | configuration file
log_connections | on | configuration file
log_destination | syslog | configuration file
log_disconnections | on | configuration file
log_duration | off | configuration file
log_line_prefix | db=%d,user=%u,app=%a,client=%h | configuration file
log_lock_waits | on | configuration file
log_min_duration_sample | 100ms | configuration file
log_min_duration_statement | 1ms | configuration file
log_statement_sample_rate | 0.01 | configuration file
log_temp_files | 0 | configuration file
log_timezone | UTC | configuration file
maintenance_work_mem | 3927MB | configuration file
max_connections | 250 | configuration file
max_parallel_workers_per_gather | 8 | configuration file
max_replication_slots | 0 | configuration file
max_stack_depth | 32MB | configuration file
max_wal_senders | 0 | configuration file
max_wal_size | 50GB | configuration file
max_worker_processes | 8 | configuration file
random_page_cost | 2 | configuration file
shared_buffers | 21679MB | configuration file
synchronous_commit | off | configuration file
temp_buffers | 1309MB | configuration file
TimeZone | UTC | configuration file
track_activities | on | configuration file
track_counts | on | configuration file
update_process_title | off | configuration file
vacuum_cost_delay | 1ms | configuration file
wal_init_zero | off | configuration file
wal_level | minimal | configuration file
wal_recycle | off | configuration file
wal_skip_threshold | 20MB | configuration file
wal_sync_method | fsync | configuration file
wal_writer_delay | 500ms | configuration file
wal_writer_flush_after | 10MB | configuration file
work_mem | 1309MB | 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
What program you're using to connect to PostgreSQL: In house Java 1.8 program, JDBC 42.2.20
Is there anything relevant or unusual in the PostgreSQL server logs?: Nope
Other info
tapesystem=# SELECT * FROM pg_config();
name |
setting
-------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
BINDIR | /usr/local/bin
DOCDIR | /usr/local/share/doc/postgresql
HTMLDIR | /usr/local/share/doc/postgresql
INCLUDEDIR | /usr/local/include
PKGINCLUDEDIR | /usr/local/include/postgresql
INCLUDEDIR-SERVER | /usr/local/include/postgresql/server
LIBDIR | /usr/local/lib
PKGLIBDIR | /usr/local/lib/postgresql
LOCALEDIR | /usr/local/share/locale
MANDIR | /usr/local/man
SHAREDIR | /usr/local/share/postgresql
SYSCONFDIR | /usr/local/etc/postgresql
PGXS | /usr/local/lib/postgresql/pgxs/src/makefiles/pgxs.mk
CONFIGURE | '--with-libraries=/usr/local/lib' '--with-includes=/usr/local/include' '--enable-thread-safety' '--with-icu' '--disable-debug' '--disable-dtrace' '--without-gssapi' '--without-ldap'
'--disable-nls' '--without-pam' '--with-openssl' '--with-system-tzdata=/usr/share/zoneinfo' '--without-libxml' '--with-llvm' '--prefix=/usr/local' '--localstatedir=/var' '--mandir=/usr/local/man' '--infodir=/usr/local/share/info/' '--build=amd64-portbld-freebsd13.0'
'build_alias=amd64-portbld-freebsd13.0' 'CC=cc' 'CFLAGS=-O2 -pipe -fstack-protector-strong -fno-strict-aliasing ' 'LDFLAGS= -L/usr/local/lib -lpthread -L/usr/local/lib -fstack-protector-strong ' 'LIBS=' 'CPPFLAGS=-I/usr/local/include' 'CXX=c++' 'CXXFLAGS=-O2
-pipe -fstack-protector-strong -fno-strict-aliasing ' 'LLVM_CONFIG=/usr/local/bin/llvm-config11' 'CPP=cpp' 'PKG_CONFIG=pkgconf' 'LDFLAGS_SL='
CC | cc
CPPFLAGS | -I/usr/local/include -I/usr/local/include -I/usr/local/include -I/usr/local/include
CFLAGS | -Wall -Wmissing-prototypes -Wpointer-arith -Wdeclaration-after-statement -Werror=vla -Wendif-labels -Wmissing-format-attribute -Wformat-security -fno-strict-aliasing -fwrapv
-Wno-unused-command-line-argument -O2 -pipe -fstack-protector-strong -fno-strict-aliasing
CFLAGS_SL | -fPIC -DPIC
LDFLAGS | -L/usr/local/lib -lpthread -L/usr/local/lib -fstack-protector-strong -L/usr/local/llvm11/lib -L/usr/local/lib -Wl,--as-needed -Wl,-R'/usr/local/lib'
LDFLAGS_EX |
LDFLAGS_SL |
LIBS | -lpgcommon -lpgport -lssl -lcrypto -lz -lreadline -lexecinfo -lm
VERSION | PostgreSQL 13.2
hw.model: Intel(R) Xeon(R) CPU E5-2620 v3 @ 2.40GHz
hw.machine: amd64
hw.ncpu: 24
hw.physmem: 137287901184
2 mirrored ZFS SSD disks. Just for fun, we briefly broke the mirror during one of these slowdowns, nothing changed.
These are the system calls made over 30 seconds from Postgres during a slowdown.
getrusage 1
access 3 exit 3 fork 3 getrandom 3 pipe2 3 procctl 3 setsid 3 thr_self 3 __sysctl 5 mmap 6 wait4 6 kill 11 select 14 sigreturn 14 rename 18 getpid 21 fsync 27 pwrite 27 openat 28 sigaction 33 write 50 fstat 56 open 56 sigprocmask 98 read 143 getppid 163 kqueue 163 fcntl 175 close 249 sendto 629 kevent 1069 recvfrom 1192 lseek 3604 fstatat 15894 Thanks for any assistance.
Best,
Robert
|