Need help identifying a periodic performance issue.

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 




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

[Postgresql General]     [Postgresql PHP]     [PHP Users]     [PHP Home]     [PHP on Windows]     [Kernel Newbies]     [PHP Classes]     [PHP Books]     [PHP Databases]     [Yosemite]

  Powered by Linux