albertodonato / query-exporter

Export Prometheus metrics from SQL queries
GNU General Public License v3.0
435 stars 101 forks source link

[postrgresql]: keep-connected: false does not disconnect after query #81

Closed eri33 closed 3 years ago

eri33 commented 3 years ago

Describe the bug

I need to disconnect from postgresql instances after each query. I specified the option "keep-connected: false" in my config.yaml on master server but the option seems to be ineffective. For example, target_host=sl101712 , I can see process pid=105708 keep running for ever

Installation details

To Reproduce

If possible, please provide detailed steps to reproduce the behavior: edit config.yaml for postgresql as mine run query-exporter check process of one postgres instance target ( you can filter with ip adress ) ps -fu postgres |grep Or check postgresql.log of postgres instance target

  1. Config file content (redacted of secrets if needed)
    databases:
    postgres_mpgbdpatroniexporter:
    dsn: postgresql://postgres:xxxxx@mpgbd-patroniexporter:5432/postgres
    keep-connected: false
    #    connect-sql:
    #      - PRAGMA application_id = 123
    #      - PRAGMA auto_vacuum = 1
    labels:
      region: MAQUETTE
      app: POC
    d_ambari_dpgbdhadoop:
    dsn: postgresql://postgres:xxxxx@dpgbd-hadoop:5432/d_ambari
    keep-connected: false
    labels:
      region: DEV
      app: DATALAKE
    postgres_sl101712:
    dsn: postgresql://postgres:xxxxx@sl101712:5432/postgres
    keep-connected: false
    labels:
      region: DEV
      app: PN IARD
    postgres_slre7900302:
    dsn: postgresql://postgres:xxxxx@slre7900302:5432/postgres
    keep-connected: false
    labels:
      region: MAQUETTE
      app: ADMIN POSTGRESQL

metrics: metric1: type: gauge description: A sample gauge metric2: type: summary description: A sample summary labels: [l1, l2] metric3: type: histogram description: A sample histogram buckets: [10, 20, 50, 100, 1000] metric4: type: enum description: A sample enum states: [foo, bar, baz]

queries: query1: interval: 20 databases: [postgres_mpgbdpatroniexporter,d_ambari_dpgbdhadoop,postgres_sl101712,postgres_slre7900302] metrics: [metric1] sql: SELECT random() / 1000000000000000 AS metric1

query2:

interval: 20

timeout: 0.5

databases: [db1, db2]

metrics: [metric2, metric3]

sql: |

SELECT abs(random() / 1000000000000000) AS metric2,

abs(random() / 10000000000000000) AS metric3,

"value1" AS l1,

"value2" AS l2

query3:

schedule: "/5 *"

databases: [db2]

metrics: [metric4]

sql: |

SELECT value FROM (

SELECT "foo" AS metric4 UNION

SELECT "bar" AS metric3 UNION

SELECT "baz" AS metric4

)

ORDER BY random()

LIMIT 1

  1. Ran query-exporter with the following command line ... query-exporter /usr/query-exporter-master/query_exporter/schemas/config.yaml -H 0.0.0.0 2021-03-10 18:56:21,732 - WARNING - query-exporter - unused entries in "metrics" section: metric2, metric3, metric4
  2. Got no disconnection after queries: On target_host=sl101712, I can see process pid=105708 (with ip adress from master) keep running for ever
    [root@sl101712 ~]# ps -fu postgres |egrep -v "bash|ps -fu postgres"
    UID         PID   PPID  C STIME TTY          TIME CMD
    postgres   2955      1  0 Jan28 ?        00:18:34 /usr/pgsql-12/bin/postmaster -D /var/lib/pgsql/12/main/data/data
    postgres   2958   2955  0 Jan28 ?        00:08:21 postgres: main: checkpointer
    postgres   2959   2955  0 Jan28 ?        00:00:48 postgres: main: background writer
    postgres   2960   2955  0 Jan28 ?        00:04:06 postgres: main: walwriter
    postgres   2961   2955  0 Jan28 ?        00:01:28 postgres: main: autovacuum launcher
    postgres   2962   2955  0 Jan28 ?        00:00:20 postgres: main: archiver   last was 0000000100000154000000C6
    postgres   2963   2955  0 Jan28 ?        00:06:29 postgres: main: stats collector
    postgres   2964   2955  0 Jan28 ?        00:04:23 postgres: main: powa   idle
    postgres   2965   2955  0 Jan28 ?        00:00:02 postgres: main: logical replication launcher
    postgres  50454   2955  0 Mar09 ?        00:00:13 postgres: main: walsender streaming_barman 172.23.208.110(36642) streaming 154/C7070780
    postgres  89260      1  0 Mar08 ?        00:00:29 /usr/bin/postgres_exporter --extend.query-path=/var/lib/pgsql/monitoring//queries.yaml
    postgres  89267   2955  0 Mar08 ?        00:00:42 postgres: main: postgres_exporter postgres 172.23.213.208(35022) idle
    postgres  89811   2955  0 Mar09 ?        00:00:00 postgres: main: postgres postgres 172.23.194.97(39928) idle
    postgres  89893   2955  0 Mar09 ?        00:00:00 postgres: main: postgres postgres 172.23.194.97(55208) idle
    postgres 103275   2955  0 18:30 ?        00:00:00 postgres: main: usr-ddo d_do 172.23.254.77(55516) idle
    postgres 103282   2955  0 18:30 ?        00:00:00 postgres: main: usr-ddo d_do 172.23.254.77(55714) idle
    postgres 103341   2955  0 18:31 ?        00:00:00 postgres: main: usr-ddo d_do 172.23.254.77(56248) idle
    postgres 103705   2955  0 18:35 ?        00:00:00 postgres: main: usr-ddo d_do 172.23.254.77(35762) idle
    postgres 105004   2955  0 18:49 ?        00:00:00 postgres: main: usr-ddo d_do 172.23.254.77(34788) idle
    postgres 105048   2955  0 18:49 ?        00:00:00 postgres: main: usr-ddo d_do 172.23.254.77(36448) idle
    postgres 105153   2955  0 18:50 ?        00:00:00 postgres: main: usr-ddo d_do 172.23.254.77(37986) idle
    postgres 105362   2955  0 18:53 ?        00:00:00 postgres: main: usr-ddo d_do 172.23.254.77(42420) idle
    postgres 105391   2955  0 18:53 ?        00:00:00 postgres: main: usr-ddo d_do 172.23.254.77(43482) idle
    postgres 105542   2955  0 18:55 ?        00:00:00 postgres: main: usr-ddo d_do 172.23.254.77(46580) idle
    postgres 105708   2955  0 18:56 ?        00:00:00 postgres: main: postgres postgres 172.23.246.38(33544) idle
    [root@sl101712 ~]#
    

On target_host=sl101712, in postgresql.log, I can see there is no disconnection ( IP address of master=172.23.246.38)

Mar 10 18:56:21 sl101712 postgresql-12-main[105708]: [10-1] [105708]: [1-1] db=[unknown],user=[unknown],app=[unknown],client=172.23.246.38 LOG:  connection received: host=172.23.246.38 port=33544
Mar 10 18:56:21 sl101712 postgresql-12-main[105708]: [11-1] [105708]: [2-1] db=postgres,user=postgres,app=[unknown],client=172.23.246.38 LOG:  connection authorized: user=postgres database=postgres SSL enabled (protocol=TLSv1.2, cipher=ECDHE-RSA-AES256-GCM-SHA384, bits=256, compression=off)
albertodonato commented 3 years ago

can you paste the output of query-exporter running with -L DEBUG?

eri33 commented 3 years ago

Hi,

FYI, I changed slincy the config.yaml file.

Here is the output with -L DEBUG:

[root@slre7900302 ~]# query-exporter /usr/query-exporter-master/query_exporter/schemas/config.yaml -H 0.0.0.0 -L DEBUG |grep sl101712
2021-03-11 19:12:28,391 - INFO - aiohttp.web - Listening on http://0.0.0.0:9560
2021-03-11 19:12:28,391 - INFO - query-exporter - version 2.6.1 starting up
2021-03-11 19:12:28,418 - DEBUG - query-exporter - connected to database "d_ambari_dpgbdhadoop"
2021-03-11 19:12:28,435 - DEBUG - query-exporter - connected to database "postgres_sl101712"
2021-03-11 19:12:28,451 - DEBUG - query-exporter - connected to database "postgres_slre7900302"
2021-03-11 19:12:28,452 - DEBUG - query-exporter - running query "query1" on database "d_ambari_dpgbdhadoop"
2021-03-11 19:12:28,452 - DEBUG - query-exporter - running query "query1" on database "postgres_sl101712"
2021-03-11 19:12:28,452 - DEBUG - query-exporter - running query "query1" on database "postgres_slre7900302"
2021-03-11 19:12:28,457 - DEBUG - query-exporter - disconnected from database "d_ambari_dpgbdhadoop"
2021-03-11 19:12:28,457 - DEBUG - query-exporter - updating metric "metric1" set 4.39496870152652e-16 {app="DATALAKE",database="d_ambari_dpgbdhadoop",region="DEV"}
2021-03-11 19:12:28,457 - DEBUG - query-exporter - updating metric "query_latency" observe 0.00133533775806427 {app="DATALAKE",database="d_ambari_dpgbdhadoop",query="query1",region="DEV"}
2021-03-11 19:12:28,457 - DEBUG - query-exporter - updating metric "queries" inc 1 {app="DATALAKE",database="d_ambari_dpgbdhadoop",query="query1",region="DEV",status="success"}
2021-03-11 19:12:28,457 - DEBUG - query-exporter - disconnected from database "postgres_sl101712"
2021-03-11 19:12:28,457 - DEBUG - query-exporter - updating metric "metric1" set 2.4450555748300573e-16 {app="PN IARD",database="postgres_sl101712",region="DEV"}
2021-03-11 19:12:28,457 - DEBUG - query-exporter - updating metric "query_latency" observe 0.0011701993644237518 {app="PN IARD",database="postgres_sl101712",query="query1",region="DEV"}
2021-03-11 19:12:28,458 - DEBUG - query-exporter - updating metric "queries" inc 1 {app="PN IARD",database="postgres_sl101712",query="query1",region="DEV",status="success"}
2021-03-11 19:12:28,459 - DEBUG - query-exporter - disconnected from database "postgres_slre7900302"
2021-03-11 19:12:28,459 - DEBUG - query-exporter - updating metric "metric1" set 7.777238405041729e-16 {app="ADMIN POSTGRESQL",database="postgres_slre7900302",region="MAQUETTE"}
2021-03-11 19:12:28,459 - DEBUG - query-exporter - updating metric "query_latency" observe 0.0008683539927005768 {app="ADMIN POSTGRESQL",database="postgres_slre7900302",query="query1",region="MAQUETTE"}
2021-03-11 19:12:28,459 - DEBUG - query-exporter - updating metric "queries" inc 1 {app="ADMIN POSTGRESQL",database="postgres_slre7900302",query="query1",region="MAQUETTE",status="success"}

2021-03-11 19:12:48,469 - DEBUG - query-exporter - connected to database "d_ambari_dpgbdhadoop"
2021-03-11 19:12:48,469 - DEBUG - query-exporter - running query "query1" on database "d_ambari_dpgbdhadoop"
2021-03-11 19:12:48,469 - DEBUG - query-exporter - connected to database "postgres_sl101712"
2021-03-11 19:12:48,470 - DEBUG - query-exporter - running query "query1" on database "postgres_sl101712"
2021-03-11 19:12:48,471 - DEBUG - query-exporter - connected to database "postgres_slre7900302"
2021-03-11 19:12:48,471 - DEBUG - query-exporter - running query "query1" on database "postgres_slre7900302"
2021-03-11 19:12:48,474 - DEBUG - query-exporter - disconnected from database "postgres_sl101712"
2021-03-11 19:12:48,474 - DEBUG - query-exporter - updating metric "metric1" set 1.0650986754954062e-16 {app="PN IARD",database="postgres_sl101712",region="DEV"}
2021-03-11 19:12:48,474 - DEBUG - query-exporter - updating metric "query_latency" observe 0.001135062426328659 {app="PN IARD",database="postgres_sl101712",query="query1",region="DEV"}
2021-03-11 19:12:48,474 - DEBUG - query-exporter - updating metric "queries" inc 1 {app="PN IARD",database="postgres_sl101712",query="query1",region="DEV",status="success"}
2021-03-11 19:12:48,474 - DEBUG - query-exporter - disconnected from database "d_ambari_dpgbdhadoop"
2021-03-11 19:12:48,475 - DEBUG - query-exporter - updating metric "metric1" set 5.33631606958806e-16 {app="DATALAKE",database="d_ambari_dpgbdhadoop",region="DEV"}
2021-03-11 19:12:48,475 - DEBUG - query-exporter - updating metric "query_latency" observe 0.0014905072748661041 {app="DATALAKE",database="d_ambari_dpgbdhadoop",query="query1",region="
2021-03-11 19:12:48,475 - DEBUG - query-exporter - updating metric "queries" inc 1 {app="DATALAKE",database="d_ambari_dpgbdhadoop",query="query1",region="DEV",status="success"}
2021-03-11 19:12:48,477 - DEBUG - query-exporter - disconnected from database "postgres_slre7900302"
2021-03-11 19:12:48,477 - DEBUG - query-exporter - updating metric "metric1" set 2.729517474027325e-16 {app="ADMIN POSTGRESQL",database="postgres_slre7900302",region="MAQUETTE"}
2021-03-11 19:12:48,477 - DEBUG - query-exporter - updating metric "query_latency" observe 0.0035823844373226166 {app="ADMIN POSTGRESQL",database="postgres_slre7900302",query="query1",
2021-03-11 19:12:48,477 - DEBUG - query-exporter - updating metric "queries" inc 1 {app="ADMIN POSTGRESQL",database="postgres_slre7900302",query="query1",region="MAQUETTE",status="succ

2021-03-11 19:13:08,470 - DEBUG - query-exporter - connected to database "d_ambari_dpgbdhadoop"
2021-03-11 19:13:08,470 - DEBUG - query-exporter - running query "query1" on database "d_ambari_dpgbdhadoop"
2021-03-11 19:13:08,471 - DEBUG - query-exporter - connected to database "postgres_sl101712"
2021-03-11 19:13:08,471 - DEBUG - query-exporter - running query "query1" on database "postgres_sl101712"
2021-03-11 19:13:08,472 - DEBUG - query-exporter - connected to database "postgres_slre7900302"
2021-03-11 19:13:08,472 - DEBUG - query-exporter - running query "query1" on database "postgres_slre7900302"
2021-03-11 19:13:08,475 - DEBUG - query-exporter - disconnected from database "d_ambari_dpgbdhadoop"
2021-03-11 19:13:08,475 - DEBUG - query-exporter - updating metric "metric1" set 8.35516860708594e-16 {app="DATALAKE",database="d_ambari_dpgbdhadoop",region="DEV"}
2021-03-11 19:13:08,475 - DEBUG - query-exporter - updating metric "query_latency" observe 0.0009423047304153442 {app="DATALAKE",database="d_ambari_dpgbdhadoop",query="query1",region="
2021-03-11 19:13:08,475 - DEBUG - query-exporter - updating metric "queries" inc 1 {app="DATALAKE",database="d_ambari_dpgbdhadoop",query="query1",region="DEV",status="success"}
2021-03-11 19:13:08,475 - DEBUG - query-exporter - disconnected from database "postgres_sl101712"
2021-03-11 19:13:08,475 - DEBUG - query-exporter - updating metric "metric1" set 4.740628580226378e-16 {app="PN IARD",database="postgres_sl101712",region="DEV"}
2021-03-11 19:13:08,475 - DEBUG - query-exporter - updating metric "query_latency" observe 0.0013022646307945251 {app="PN IARD",database="postgres_sl101712",query="query1",region="DEV"
2021-03-11 19:13:08,475 - DEBUG - query-exporter - updating metric "queries" inc 1 {app="PN IARD",database="postgres_sl101712",query="query1",region="DEV",status="success"}
2021-03-11 19:13:08,477 - DEBUG - query-exporter - disconnected from database "postgres_slre7900302"
2021-03-11 19:13:08,477 - DEBUG - query-exporter - updating metric "metric1" set 7.37155206797965e-16 {app="ADMIN POSTGRESQL",database="postgres_slre7900302",region="MAQUETTE"}
2021-03-11 19:13:08,477 - DEBUG - query-exporter - updating metric "query_latency" observe 0.0031310655176639557 {app="ADMIN POSTGRESQL",database="postgres_slre7900302",query="query1",
2021-03-11 19:13:08,478 - DEBUG - query-exporter - updating metric "queries" inc 1 {app="ADMIN POSTGRESQL",database="postgres_slre7900302",query="query1",region="MAQUETTE",status="succ

2021-03-11 19:13:28,462 - DEBUG - query-exporter - connected to database "d_ambari_dpgbdhadoop"
2021-03-11 19:13:28,462 - DEBUG - query-exporter - running query "query1" on database "d_ambari_dpgbdhadoop"
2021-03-11 19:13:28,462 - DEBUG - query-exporter - connected to database "postgres_sl101712"
2021-03-11 19:13:28,462 - DEBUG - query-exporter - running query "query1" on database "postgres_sl101712"
2021-03-11 19:13:28,463 - DEBUG - query-exporter - connected to database "postgres_slre7900302"
2021-03-11 19:13:28,463 - DEBUG - query-exporter - running query "query1" on database "postgres_slre7900302"
2021-03-11 19:13:28,466 - DEBUG - query-exporter - disconnected from database "postgres_sl101712"
2021-03-11 19:13:28,466 - DEBUG - query-exporter - updating metric "metric1" set 6.592250386501206e-16 {app="PN IARD",database="postgres_sl101712",region="DEV"}
2021-03-11 19:13:28,466 - DEBUG - query-exporter - updating metric "query_latency" observe 0.0011374391615390778 {app="PN IARD",database="postgres_sl101712",query="query1",region="DEV"
2021-03-11 19:13:28,466 - DEBUG - query-exporter - updating metric "queries" inc 1 {app="PN IARD",database="postgres_sl101712",query="query1",region="DEV",status="success"}
2021-03-11 19:13:28,467 - DEBUG - query-exporter - disconnected from database "d_ambari_dpgbdhadoop"
2021-03-11 19:13:28,467 - DEBUG - query-exporter - updating metric "metric1" set 7.66877793706953e-16 {app="DATALAKE",database="d_ambari_dpgbdhadoop",region="DEV"}
2021-03-11 19:13:28,467 - DEBUG - query-exporter - updating metric "query_latency" observe 0.001426246017217636 {app="DATALAKE",database="d_ambari_dpgbdhadoop",query="query1",region="D
2021-03-11 19:13:28,467 - DEBUG - query-exporter - updating metric "queries" inc 1 {app="DATALAKE",database="d_ambari_dpgbdhadoop",query="query1",region="DEV",status="success"}
2021-03-11 19:13:28,469 - DEBUG - query-exporter - disconnected from database "postgres_slre7900302"
2021-03-11 19:13:28,469 - DEBUG - query-exporter - updating metric "metric1" set 3.26952180639946e-16 {app="ADMIN POSTGRESQL",database="postgres_slre7900302",region="MAQUETTE"}
2021-03-11 19:13:28,469 - DEBUG - query-exporter - updating metric "query_latency" observe 0.003657922148704529 {app="ADMIN POSTGRESQL",database="postgres_slre7900302",query="query1",r
2021-03-11 19:13:28,469 - DEBUG - query-exporter - updating metric "queries" inc 1 {app="ADMIN POSTGRESQL",database="postgres_slre7900302",query="query1",region="MAQUETTE",status="succ

2021-03-11 19:13:48,473 - DEBUG - query-exporter - connected to database "d_ambari_dpgbdhadoop"
2021-03-11 19:13:48,473 - DEBUG - query-exporter - running query "query1" on database "d_ambari_dpgbdhadoop"
2021-03-11 19:13:48,473 - DEBUG - query-exporter - connected to database "postgres_sl101712"
2021-03-11 19:13:48,473 - DEBUG - query-exporter - running query "query1" on database "postgres_sl101712"
2021-03-11 19:13:48,475 - DEBUG - query-exporter - connected to database "postgres_slre7900302"
2021-03-11 19:13:48,475 - DEBUG - query-exporter - running query "query1" on database "postgres_slre7900302"
2021-03-11 19:13:48,477 - DEBUG - query-exporter - disconnected from database "d_ambari_dpgbdhadoop"
2021-03-11 19:13:48,478 - DEBUG - query-exporter - updating metric "metric1" set 4.29883875418454e-16 {app="DATALAKE",database="d_ambari_dpgbdhadoop",region="DEV"}
2021-03-11 19:13:48,478 - DEBUG - query-exporter - updating metric "query_latency" observe 0.0010924451053142548 {app="DATALAKE",database="d_ambari_dpgbdhadoop",query="query1",region="
2021-03-11 19:13:48,478 - DEBUG - query-exporter - updating metric "queries" inc 1 {app="DATALAKE",database="d_ambari_dpgbdhadoop",query="query1",region="DEV",status="success"}
2021-03-11 19:13:48,478 - DEBUG - query-exporter - disconnected from database "postgres_sl101712"
2021-03-11 19:13:48,478 - DEBUG - query-exporter - updating metric "metric1" set 2.4340254693845154e-16 {app="PN IARD",database="postgres_sl101712",region="DEV"}
2021-03-11 19:13:48,478 - DEBUG - query-exporter - updating metric "query_latency" observe 0.0011258013546466827 {app="PN IARD",database="postgres_sl101712",query="query1",region="DEV"
2021-03-11 19:13:48,478 - DEBUG - query-exporter - updating metric "queries" inc 1 {app="PN IARD",database="postgres_sl101712",query="query1",region="DEV",status="success"}
2021-03-11 19:13:48,480 - DEBUG - query-exporter - disconnected from database "postgres_slre7900302"
2021-03-11 19:13:48,480 - DEBUG - query-exporter - updating metric "metric1" set 2.8986651065050496e-16 {app="ADMIN POSTGRESQL",database="postgres_slre7900302",region="MAQUETTE"}
2021-03-11 19:13:48,480 - DEBUG - query-exporter - updating metric "query_latency" observe 0.003119003027677536 {app="ADMIN POSTGRESQL",database="postgres_slre7900302",query="query1",r
2021-03-11 19:13:48,480 - DEBUG - query-exporter - updating metric "queries" inc 1 {app="ADMIN POSTGRESQL",database="postgres_slre7900302",query="query1",region="MAQUETTE",status="succ

Unfortunately, the deconnection doesn't happen:

[root@sl101712 ~]# date; ps -fu postgres |grep 172.23.246.38; date
Thu Mar 11 19:13:55 CET 2021
postgres 113187   2955  0 19:12 ?        00:00:00 postgres: main: postgres postgres 172.23.246.38(34542) idle
Thu Mar 11 19:13:55 CET 2021
albertodonato commented 3 years ago

uhm, that last ps only shows the postgres user connected to the postgres db. That's not the exporter?

eri33 commented 3 years ago

Pid 113187 is a postgres process session on sl101712 coming from client 172.23.246.38 On sl101712, process 113187 appears once I launched the query_exporter on 172.23.246.38
On sl101712, process 113187 disappears once I stopped the query_exporter on 172.23.246.38

eri33 commented 3 years ago

Process 113187 is not exporter. It is a process session.