postgres_exporter icon indicating copy to clipboard operation
postgres_exporter copied to clipboard

Fix connection issue to multiple databases.

Open askomorokhov opened this issue 4 years ago • 1 comments

This PR fixes the issue https://github.com/prometheus-community/postgres_exporter/issues/528

This also speeds up response time by about twice and prevents connection errors (pq: sorry, too many clients already).

Tested on a hundred databases in a single server.


Before:

Time taken for tests: 213.938 seconds

ab -n 100 http://localhost:42006/metrics


[root@72cc76a6022e /]# ab -n 100 http://localhost:42006/metrics
This is ApacheBench, Version 2.3 <$Revision: 1843412 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking localhost (be patient).....done


Server Software:        
Server Hostname:        localhost
Server Port:            42006

Document Path:          /metrics
Document Length:        490547 bytes

Concurrency Level:      1
Time taken for tests:   213.938 seconds
Complete requests:      100
Failed requests:        98
   (Connect: 0, Receive: 0, Length: 98, Exceptions: 0)
Total transferred:      49065333 bytes
HTML transferred:       49054133 bytes
Requests per second:    0.47 [#/sec] (mean)
Time per request:       2139.381 [ms] (mean)
Time per request:       2139.381 [ms] (mean, across all concurrent requests)
Transfer rate:          223.97 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.0      0       0
Processing:  2096 2139  38.6   2135    2418
Waiting:     2092 2132  38.4   2127    2412
Total:       2097 2139  38.6   2135    2418

Percentage of the requests served within a certain time (ms)
  50%   2135
  66%   2141
  75%   2145
  80%   2151
  90%   2156
  95%   2172
  98%   2345
  99%   2418
 100%   2418 (longest request)

Too many connection errors: level=error ts=2021-05-05T07:58:24.170Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db49?sslmode=disable): pq: sorry, too many clients already"

Connection errors

[root@72cc76a6022e exporters]# ./postgres_exporter --auto-discover-databases --exclude-databases=template0,template1,postgres,pmm-managed-dev,azure_maintenance --web.listen-address=:42006 --log.level="error"
level=error ts=2021-05-05T07:58:24.170Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db49?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:25.176Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db64?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:26.203Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db64?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:27.219Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db64?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:28.227Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db49?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:29.311Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db49?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:30.386Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db49?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:31.426Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db49?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:32.433Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db64?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:33.465Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db64?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:34.505Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db49?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:35.570Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db64?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:36.610Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db64?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:37.618Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db49?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:38.731Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db64?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:39.737Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db64?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:40.773Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db49?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:41.794Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db49?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:42.879Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db49?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:43.899Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db49?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:44.921Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db64?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:45.956Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db64?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:46.999Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db64?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:48.062Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db49?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:49.089Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db49?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:50.101Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db64?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:51.228Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db64?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:52.251Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db49?sslmode=disable): pq: sorry, too many clients already"
level=error ts=2021-05-05T07:58:53.265Z caller=postgres_exporter.go:1624 err="Error opening connection to database (postgresql://postgres:PASSWORD_REMOVED@postgres:5432/my_db49?sslmode=disable): pq: sorry, too many clients already"

Error on DROP DATABASE

postgres=# DROP DATABASE my_db1;
ERROR:  database "my_db1" is being accessed by other users
DETAIL:  There is 1 other session using the database.
postgres=# 
postgres=# select * FROM pg_stat_activity WHERE state='idle' AND query='SELECT version();' LIMIT 2;
-[ RECORD 1 ]----+------------------------------
datid            | 16384
datname          | my_db1
pid              | 22309
leader_pid       | 
usesysid         | 10
usename          | postgres
application_name | 
client_addr      | 172.18.0.4
client_hostname  | 
client_port      | 46050
backend_start    | 2021-05-05 07:58:22.989406+00
xact_start       | 
query_start      | 2021-05-05 08:36:07.181658+00
state_change     | 2021-05-05 08:36:07.181808+00
wait_event_type  | Client
wait_event       | ClientRead
state            | idle
backend_xid      | 
backend_xmin     | 
query            | SELECT version();
backend_type     | client backend
-[ RECORD 2 ]----+------------------------------
datid            | 16385
datname          | my_db2
pid              | 22310
leader_pid       | 
usesysid         | 10
usename          | postgres
application_name | 
client_addr      | 172.18.0.4
client_hostname  | 
client_port      | 46052
backend_start    | 2021-05-05 07:58:23.000251+00
xact_start       | 
query_start      | 2021-05-05 08:36:05.063158+00
state_change     | 2021-05-05 08:36:05.063345+00
wait_event_type  | Client
wait_event       | ClientRead
state            | idle
backend_xid      | 
backend_xmin     | 
query            | SELECT version();
backend_type     | client backend

postgres=# select COUNT(*) FROM pg_stat_activity WHERE state='idle' AND query='SELECT version();';
-[ RECORD 1 ]
count | 98

postgres=# 

After:

Time taken for tests: 118.641 seconds

ab -n 100 http://localhost:42006/metrics

[root@72cc76a6022e /]# ab -n 100 http://localhost:42006/metrics This is ApacheBench, Version 2.3 Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/ Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking localhost (be patient).....done

Server Software:
Server Hostname: localhost Server Port: 42006

Document Path: /metrics Document Length: 490369 bytes

Concurrency Level: 1 Time taken for tests: 118.641 seconds Complete requests: 100 Failed requests: 99 (Connect: 0, Receive: 0, Length: 99, Exceptions: 0) Total transferred: 49070954 bytes HTML transferred: 49059754 bytes Requests per second: 0.84 [#/sec] (mean) Time per request: 1186.406 [ms] (mean) Time per request: 1186.406 [ms] (mean, across all concurrent requests) Transfer rate: 403.92 [Kbytes/sec] received

Connection Times (ms) min mean[+/-sd] median max Connect: 0 0 0.1 0 0 Processing: 898 1186 193.1 1142 1870 Waiting: 892 1179 192.3 1135 1863 Total: 898 1186 193.2 1143 1870

Percentage of the requests served within a certain time (ms) 50% 1143 66% 1217 75% 1292 80% 1321 90% 1463 95% 1600 98% 1867 99% 1870 100% 1870 (longest request) [root@72cc76a6022e /]#

No errors in logs:

[root@72cc76a6022e exporters]# ./postgres_exporter --auto-discover-databases --exclude-databases=template0,template1,postgres,pmm-managed-dev,azure_maintenance --web.listen-address=:42006 --log.level="error"

No error on DROP DATABASE:

postgres=# DROP DATABASE my_db1;
DROP DATABASE
postgres=# 
postgres=# select COUNT(*) FROM pg_stat_activity WHERE state='idle' AND query='SELECT version();';
-[ RECORD 1 ]
count | 0

askomorokhov avatar May 05 '21 09:05 askomorokhov

Any idea when this can be merged? The inability to drop a database making cleanup difficult in our CI pipeline.

scott-kausler avatar May 28 '21 17:05 scott-kausler