Re: pgsql connection timeone

Hi,

before timeout started this was the last automatic vacuum entry's:

2017-01-25 10:47:07 EET [5995-1] LOG: automatic vacuum of table "13Tim07Tuning.pg_catalog.pg_attribute": index scans: 1
pages: 0 removed, 261 remain
tuples: 3547 removed, 8812 remain
buffer usage: 927 hits, 112 misses, 161 dirtied
avg read rate: 1.438 MB/s, avg write rate: 2.067 MB/s
system usage: CPU 0.02s/0.00u sec elapsed 0.60 sec
2017-01-25 10:47:07 EET [5995-2] LOG: automatic analyze of table "13Tim07Tuning.pg_catalog.pg_class" system usage: CPU 0.00s/0.00u sec elapsed 0.08 sec
2017-01-25 10:47:07 EET [5995-3] LOG: automatic vacuum of table "13Tim07Tuning.pg_catalog.pg_index": index scans: 1
pages: 0 removed, 10 remain
tuples: 14 removed, 312 remain
buffer usage: 62 hits, 5 misses, 15 dirtied
avg read rate: 0.767 MB/s, avg write rate: 2.301 MB/s
system usage: CPU 0.00s/0.00u sec elapsed 0.05 sec
2017-01-25 10:47:10 EET [6060-1] LOG: automatic analyze of table "12westm11.pg_catalog.pg_type" system usage: CPU 0.00s/0.00u sec elapsed 0.08 sec
2017-01-25 10:47:10 EET [6060-2] LOG: automatic analyze of table "12westm11.pg_catalog.pg_attribute" system usage: CPU 0.02s/0.01u sec elapsed 0.12 sec
2017-01-25 10:48:30 EET [28355-4597] LOG: checkpoint starting: time
2017-01-25 10:49:34 EET [6222-1]XXXX(at)YYYY FATAL: canceling authentication due to timeout

----- Original Message -----

From: "Vucomir Ianculov" <vukomir(at)os-ux(dot)com>
To: pgsql-performance(at)postgresql(dot)org
Sent: Wednesday, January 25, 2017 11:23:39 AM
Subject: [PERFORM] pgsql connection timeone

Hi,

i'm seeing a lot of connection time out in postgresql log

2017-01-25 11:09:47 EET [6897-1] XXX(at)YYY FATAL: canceling authentication due to timeout
2017-01-25 11:10:15 EET [6901-1] XXX(at)YYY FATAL: canceling authentication due to timeout
2017-01-25 11:10:17 EET [6902-1] xxx(at)YYY FATAL: canceling authentication due to timeout
2017-01-25 11:10:33 EET [6906-1] xxxx(at)YYY FATAL: canceling authentication due to timeout
2017-01-25 11:10:44 EET [6912-1] xxx(at)YYY FATAL: canceling authentication due to timeout
2017-01-25 11:10:48 EET [6913-1] xxx(at)YYY FATAL: canceling authentication due to timeout
2017-01-25 11:10:52 EET [6920-1] xxx(at)YYY: canceling authentication due to timeout
2017-01-25 11:10:52 EET [6930-1] postgres(at)postgres FATAL: canceling authentication due to timeout
2017-01-25 11:10:53 EET [6921-1] xxx(at)YYY FATAL: canceling authentication due to timeout
2017-01-25 11:11:08 EET [6933-1] xxx(at)YYY FATAL: canceling authentication due to timeout

i also tired to login as postgres user from command line.

postgres(at)sppgsql01:~$ psql
psql: server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.

server load is ok, under 1,

memory usage is also ok.

root(at)server ~ # free -m
total used free shared buff/cache available
Mem: 128908 3398 795 31671 124714 92980
Swap: 8191 1418 6773

system is a ubuntu 16.04 and i'm using postgresql 9.3

connection limit is at 500 at the moment i have 180 connection, authentication_timeout is default 1 min.

here is the postgresql.conf

data_directory = '/var/lib/postgresql/9.3/main' # use data in another directory
# (change requires restart)
hba_file = '/etc/postgresql/9.3/main/pg_hba.conf' # host-based authentication file
# (change requires restart)
ident_file = '/etc/postgresql/9.3/main/pg_ident.conf' # ident configuration file
# (change requires restart)
external_pid_file = '/var/run/postgresql/9.3-main.pid' # write an extra PID file
# (change requires restart)
listen_addresses = '*' # what IP address(es) to listen on;
# comma-separated list of addresses;
# defaults to 'localhost'; use '*' for all
# (change requires restart)
port = 5432 # (change requires restart)
max_connections = 500 # (change requires restart)
unix_socket_directories = '/var/run/postgresql' # comma-separated list of directories
# (change requires restart)
# (change requires restart)
# (change requires restart)
# (change requires restart)
ssl = on # (change requires restart)
ssl_ciphers = 'DEFAULT:!LOW:!EXP:!MD5:@STRENGTH' # allowed SSL ciphers
# (change requires restart)
ssl_cert_file = 'server.crt' # (change requires restart)
ssl_key_file = 'server.key' # (change requires restart)
password_encryption = on
# 0 selects the system default
# 0 selects the system default
# 0 selects the system default
# (change requires restart)
# (change requires restart)
# in kB, or -1 for no limit
max_files_per_process = 5000 # min 25
# (change requires restart)
vacuum_cost_delay = 20 # 0-100 milliseconds
vacuum_cost_page_hit = 1 # 0-10000 credits
vacuum_cost_page_miss = 10 # 0-10000 credits
vacuum_cost_page_dirty = 20 # 0-10000 credits
vacuum_cost_limit = 200 # 1-10000 credits
# (change requires restart)
fsync = on # turns forced synchronization on or off
synchronous_commit = on # synchronization level;
# off, local, remote_write, or on
wal_sync_method = fsync # the default is the first option
# supported by the operating system:
# open_datasync
# fdatasync (default on Linux)
# fsync
# fsync_writethrough
# open_sync
full_page_writes = on # recover from partial page writes
wal_buffers = -1 # min 32kB, -1 sets based on shared_buffers
# (change requires restart)
wal_writer_delay = 200ms # 1-10000 milliseconds
commit_delay = 0 # range 0-100000, in microseconds
commit_siblings = 5 # range 1-1000
checkpoint_segments = 64 # in logfile segments, min 1, 16MB each
checkpoint_timeout = 15min # range 30s-1h
checkpoint_completion_target = 0.9 # checkpoint target duration, 0.0 - 1.0
checkpoint_warning = 30s # 0 disables

log_checkpoints = on
log_line_prefix = '%t [%p-%l] %q%u(at)%d ' # special values:

log_timezone = 'Europe/Bucharest'
track_activities = on
track_counts = on
stats_temp_directory = '/var/run/postgresql/9.3-main.pg_stat_tmp'
autovacuum = on # Enable autovacuum subprocess? 'on'
# requires track_counts to also be on.
log_autovacuum_min_duration = 0 # -1 disables, 0 logs all actions and

autovacuum_max_workers = 5 # max number of autovacuum subprocesses
# (change requires restart)
autovacuum_naptime = 5min # time between autovacuum runs
autovacuum_vacuum_threshold = 500 # min number of row updates before
# vacuum
autovacuum_analyze_threshold = 500 # min number of row updates before
# analyze
autovacuum_vacuum_scale_factor = 0.4 # fraction of table size before vacuum
autovacuum_analyze_scale_factor = 0.2 # fraction of table size before analyze

autovacuum_vacuum_cost_delay = 20ms # default vacuum cost delay for

datestyle = 'iso, mdy'
timezone = 'Europe/Bucharest'

client_encoding = sql_ascii # actually, defaults to database
# encoding
lc_messages = 'C' # locale for system error message
# strings
lc_monetary = 'C' # locale for monetary formatting
lc_numeric = 'C' # locale for number formatting
lc_time = 'C' # locale for time formatting
default_text_search_config = 'pg_catalog.english'
# (change requires restart)
# (change requires restart)
# directory 'conf.d'
default_statistics_target = 100 # pgtune wizard 2016-12-11
maintenance_work_mem = 1GB # pgtune wizard 2016-12-11
constraint_exclusion = on # pgtune wizard 2016-12-11
effective_cache_size = 88GB # pgtune wizard 2016-12-11
work_mem = 64MB # pgtune wizard 2016-12-11
wal_buffers = 32MB # pgtune wizard 2016-12-11
shared_buffers = 30GB # pgtune wizard 2016-12-11

dose anyone know why this thing are happening?

Thanks.

Br,
Vuko