Convert pg_stat_database to new collector model

[sysadmind]

Signed-off-by: Joe Adams [email protected]

[sysadmind]

Ping @SuperQ

[SuperQ]

CC @Sticksman

[rcrane]

It seems that all "pg_stat_database_tup_*" (as shown here) are not exported anymore in v0.13.0 while they are exported in v0.12.1 (tested with postgres14).
The updated readme states that stat_database is enabled by default.
Do I have to enable something else to get these stats in v0.13 or is there something else I can try?

Sorry, I just found this post reporting the same issue.

[Sticksman]

That's odd, they should be getting returned: https://github.com./prometheus-community/postgres_exporter/blob/master/collector/pg_stat_database.go#L389

I also see it in the dump you provided:

# HELP pg_stat_database_tup_deleted Number of rows deleted by queries in this database
# TYPE pg_stat_database_tup_deleted counter
pg_stat_database_tup_deleted{datid="0",datname="",server="localhost:5432"} 0
pg_stat_database_tup_deleted{datid="1",datname="template1",server="localhost:5432"} 0
pg_stat_database_tup_deleted{datid="13394",datname="template0",server="localhost:5432"} 0
pg_stat_database_tup_deleted{datid="13395",datname="postgres",server="localhost:5432"} 0
# HELP pg_stat_database_tup_fetched Number of rows fetched by queries in this database
# TYPE pg_stat_database_tup_fetched counter
pg_stat_database_tup_fetched{datid="0",datname="",server="localhost:5432"} 595
pg_stat_database_tup_fetched{datid="1",datname="template1",server="localhost:5432"} 0
pg_stat_database_tup_fetched{datid="13394",datname="template0",server="localhost:5432"} 0
pg_stat_database_tup_fetched{datid="13395",datname="postgres",server="localhost:5432"} 3555
# HELP pg_stat_database_tup_inserted Number of rows inserted by queries in this database
# TYPE pg_stat_database_tup_inserted counter
pg_stat_database_tup_inserted{datid="0",datname="",server="localhost:5432"} 2
pg_stat_database_tup_inserted{datid="1",datname="template1",server="localhost:5432"} 0
pg_stat_database_tup_inserted{datid="13394",datname="template0",server="localhost:5432"} 0
pg_stat_database_tup_inserted{datid="13395",datname="postgres",server="localhost:5432"} 0
# HELP pg_stat_database_tup_returned Number of rows returned by queries in this database
# TYPE pg_stat_database_tup_returned counter
pg_stat_database_tup_returned{datid="0",datname="",server="localhost:5432"} 1042
pg_stat_database_tup_returned{datid="1",datname="template1",server="localhost:5432"} 0
pg_stat_database_tup_returned{datid="13394",datname="template0",server="localhost:5432"} 0
pg_stat_database_tup_returned{datid="13395",datname="postgres",server="localhost:5432"} 178478
# HELP pg_stat_database_tup_updated Number of rows updated by queries in this database
# TYPE pg_stat_database_tup_updated counter
pg_stat_database_tup_updated{datid="0",datname="",server="localhost:5432"} 1
pg_stat_database_tup_updated{datid="1",datname="template1",server="localhost:5432"} 0
pg_stat_database_tup_updated{datid="13394",datname="template0",server="localhost:5432"} 0
pg_stat_database_tup_updated{datid="13395",datname="postgres",server="localhost:5432"} 0

[rcrane]

I guess, I could have expressed that better. The "as shown here" link was meant to show the expected output.

I attached two outputs I took from my tests using

quay.io/prometheuscommunity/postgres-exporter:v0.13.0
and
quay.io/prometheuscommunity/postgres-exporter:v0.12.1

both with postgres 14.

metrics_13_0.txt
metrics_12_1.txt

One example is "pg_stat_database_tup_returned", which exists in the 12.1 but not in 13.0.

[Sticksman]

Can you check 0.13.2? I don't expect there to be a difference, but just so we're sure.

[algchoo]

Can you check 0.13.2? I don't expect there to be a difference, but just so we're sure.

I ran version 0.13.2 of the exporter against PostgreSQL 15.3. I used pgbench to see if having something going on would help generate those metrics, but that hasn't been successful. I confirmed that using version 0.12.1 of the exporter with PostgreSQL 15.3 does provide the expected metrics.

Here's everything I'm getting for pg_stat_database metrics using 0.13.x

# HELP pg_stat_database_conflicts_confl_bufferpin Number of queries in this database that have been canceled due to pinned buffers
# TYPE pg_stat_database_conflicts_confl_bufferpin counter
pg_stat_database_conflicts_confl_bufferpin{datid="1",datname="template1",server="localhost:5432"} 0
pg_stat_database_conflicts_confl_bufferpin{datid="16384",datname="dev",server="localhost:5432"} 0
pg_stat_database_conflicts_confl_bufferpin{datid="4",datname="template0",server="localhost:5432"} 0
pg_stat_database_conflicts_confl_bufferpin{datid="5",datname="postgres",server="localhost:5432"} 0
# HELP pg_stat_database_conflicts_confl_deadlock Number of queries in this database that have been canceled due to deadlocks
# TYPE pg_stat_database_conflicts_confl_deadlock counter
pg_stat_database_conflicts_confl_deadlock{datid="1",datname="template1",server="localhost:5432"} 0
pg_stat_database_conflicts_confl_deadlock{datid="16384",datname="dev",server="localhost:5432"} 0
1pg_stat_database_conflicts_confl_deadlock{datid="4",datname="template0",server="localhost:5432"} 0
pg_stat_database_conflicts_confl_deadlock{datid="5",datname="postgres",server="localhost:5432"} 0
# HELP pg_stat_database_conflicts_confl_lock Number of queries in this database that have been canceled due to lock timeouts
# TYPE pg_stat_database_conflicts_confl_lock counter
pg_stat_database_conflicts_confl_lock{datid="1",datname="template1",server="localhost:5432"} 0
pg_stat_database_conflicts_confl_lock{datid="16384",datname="dev",server="localhost:5432"} 0
pg_stat_database_conflicts_confl_lock{datid="4",datname="template0",server="localhost:5432"} 0
pg_stat_database_conflicts_confl_lock{datid="5",datname="postgres",server="localhost:5432"} 0
# HELP pg_stat_database_conflicts_confl_snapshot Number of queries in this database that have been canceled due to old snapshots
# TYPE pg_stat_database_conflicts_confl_snapshot counter
pg_stat_database_conflicts_confl_snapshot{datid="1",datname="template1",server="localhost:5432"} 0
pg_stat_database_conflicts_confl_snapshot{datid="16384",datname="dev",server="localhost:5432"} 0
pg_stat_database_conflicts_confl_snapshot{datid="4",datname="template0",server="localhost:5432"} 0
pg_stat_database_conflicts_confl_snapshot{datid="5",datname="postgres",server="localhost:5432"} 0
# HELP pg_stat_database_conflicts_confl_tablespace Number of queries in this database that have been canceled due to dropped tablespaces
# TYPE pg_stat_database_conflicts_confl_tablespace counter
pg_stat_database_conflicts_confl_tablespace{datid="1",datname="template1",server="localhost:5432"} 0
pg_stat_database_conflicts_confl_tablespace{datid="16384",datname="dev",server="localhost:5432"} 0
pg_stat_database_conflicts_confl_tablespace{datid="4",datname="template0",server="localhost:5432"} 0
pg_stat_database_conflicts_confl_tablespace{datid="5",datname="postgres",server="localhost:5432"} 0

[Sticksman]

Ok, interesting. We're only getting metrics from this:

postgres_exporter/cmd/postgres_exporter/postgres_exporter.go

Line 166 in 716ac23

"pg_stat_database_conflicts": {

This means that pg_stat_database metrics from this collector aren't being emitted at all.

[Sticksman]

It feels like something super dumb, like somehow a label name and a namespace are colliding

[sysadmind]

I have a feeling that it has something to do with a NULL column. Can someone try with log level turned up to debug and post the logs?

[algchoo]

Here's what I'm getting with the log level turned up to debug. I see some messages around columns being discarded due to version incompatibility and then below that I don't ever see the namespace pg_stat_database being queried, granted I'm assuming that is expected, not sure. Hope this helps!

ts=2023-07-27T12:32:18.712Z caller=server.go:74 level=info msg="Established new database connection" fingerprint=localhost:5432
ts=2023-07-27T12:32:18.727Z caller=postgres_exporter.go:594 level=debug msg="Querying PostgreSQL version" server=localhost:5432
ts=2023-07-27T12:32:18.727Z caller=postgres_exporter.go:622 level=info msg="Semantic version changed" server=localhost:5432 from=0.0.0 to=15.3.0
ts=2023-07-27T12:32:18.727Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=flush_location
ts=2023-07-27T12:32:18.727Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=sent_location
ts=2023-07-27T12:32:18.728Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=pg_xlog_location_diff
ts=2023-07-27T12:32:18.728Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=write_location
ts=2023-07-27T12:32:18.728Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=procpid
ts=2023-07-27T12:32:18.728Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=replay_location
ts=2023-07-27T12:32:18.728Z caller=pg_setting.go:35 level=debug msg="Querying pg_setting view" server=localhost:5432
ts=2023-07-27T12:32:18.728Z caller=postgres_exporter.go:594 level=debug msg="Querying PostgreSQL version" server=localhost:5432
ts=2023-07-27T12:32:18.734Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_database_conflicts
ts=2023-07-27T12:32:18.734Z caller=pg_setting.go:35 level=debug msg="Querying pg_setting view" server=localhost:5432
ts=2023-07-27T12:32:18.735Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_locks
ts=2023-07-27T12:32:18.745Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_archiver
ts=2023-07-27T12:32:18.746Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_replication
ts=2023-07-27T12:32:18.747Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_activity
ts=2023-07-27T12:32:18.750Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_replication_slots
ts=2023-07-27T12:32:18.757Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_database_conflicts
ts=2023-07-27T12:32:18.759Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_archiver
ts=2023-07-27T12:32:18.759Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_locks
ts=2023-07-27T12:32:18.760Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_activity
ts=2023-07-27T12:32:18.762Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_replication
ts=2023-07-27T12:32:18.765Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_replication_slots

[Sticksman]

Hm, I would have expected it to be registered at least.

[sysadmind]

The debug logs do show the problem. I don't know why your logs don't include it. I spun up postgres locally with the exporter log level set to debug and I have these logs:

ts=2023-07-27T18:07:12.528Z caller=server.go:74 level=info msg="Established new database connection" fingerprint=localhost:5432
ts=2023-07-27T18:07:12.530Z caller=pg_stat_database.go:280 level=debug collector=stat_database msg="Skipping collecting metric because it has no datname"
ts=2023-07-27T18:07:12.530Z caller=pg_stat_database.go:348 level=debug collector=stat_database msg="Skipping collecting metric because it has no stats_reset"
ts=2023-07-27T18:07:12.530Z caller=pg_stat_database.go:348 level=debug collector=stat_database msg="Skipping collecting metric because it has no stats_reset"
ts=2023-07-27T18:07:12.530Z caller=pg_stat_database.go:348 level=debug collector=stat_database msg="Skipping collecting metric because it has no stats_reset"
ts=2023-07-27T18:07:12.530Z caller=pg_stat_database.go:348 level=debug collector=stat_database msg="Skipping collecting metric because it has no stats_reset"
ts=2023-07-27T18:07:12.530Z caller=collector.go:194 level=debug msg="collector succeeded" name=stat_database duration_seconds=0.001862776

The first skip is expected because the datname is NULL. The labels won't come out right with that field NULL.

This was caused by 2 PRs together.

First, pg_stat_database collector was changed to always use NULL-able data types. The stats_reset field is expected to be NULL if the stats have never been reset. See the change here: https://github.com./prometheus-community/postgres_exporter/pull/823/files#diff-19ef1ff88df9efd6fea2fe321a720b0a44edc1daab43571ac07460666efc3697L412

In a later PR the metric line was skipped entirely if the field is NULL. This is the change that would have stopped reporting the metrics entirely.

In this scenario, only the labels being NULL should skip the whole row. Any other fields being NULL (should only be stats_reset) should only skip that single metric.

[Sticksman]

Just ran a docker container with postgres 14 and a built v0.13.2. I'm seeing stat_database metrics get emitted:

# TYPE pg_stat_database_tup_deleted counter
pg_stat_database_tup_deleted{datid="0",datname="unknown"} 0
pg_stat_database_tup_deleted{datid="1",datname="template1"} 0
pg_stat_database_tup_deleted{datid="13779",datname="template0"} 0
pg_stat_database_tup_deleted{datid="13780",datname="postgres"} 0
pg_stat_database_tup_deleted{datid="16384",datname="circle_test"} 0
# HELP pg_stat_database_tup_fetched Number of rows fetched by queries in this database
# TYPE pg_stat_database_tup_fetched counter
pg_stat_database_tup_fetched{datid="0",datname="unknown"} 17
pg_stat_database_tup_fetched{datid="1",datname="template1"} 0
pg_stat_database_tup_fetched{datid="13779",datname="template0"} 0
pg_stat_database_tup_fetched{datid="13780",datname="postgres"} 816
pg_stat_database_tup_fetched{datid="16384",datname="circle_test"} 1198
# HELP pg_stat_database_tup_inserted Number of rows inserted by queries in this database
# TYPE pg_stat_database_tup_inserted counter
pg_stat_database_tup_inserted{datid="0",datname="unknown"} 1
pg_stat_database_tup_inserted{datid="1",datname="template1"} 0
pg_stat_database_tup_inserted{datid="13779",datname="template0"} 0
pg_stat_database_tup_inserted{datid="13780",datname="postgres"} 0
pg_stat_database_tup_inserted{datid="16384",datname="circle_test"} 0
# HELP pg_stat_database_tup_returned Number of rows returned by queries in this database
# TYPE pg_stat_database_tup_returned counter
pg_stat_database_tup_returned{datid="0",datname="unknown"} 32
pg_stat_database_tup_returned{datid="1",datname="template1"} 0
pg_stat_database_tup_returned{datid="13779",datname="template0"} 0
pg_stat_database_tup_returned{datid="13780",datname="postgres"} 897
pg_stat_database_tup_returned{datid="16384",datname="circle_test"} 1684
# HELP pg_stat_database_tup_updated Number of rows updated by queries in this database
# TYPE pg_stat_database_tup_updated counter
pg_stat_database_tup_updated{datid="0",datname="unknown"} 0
pg_stat_database_tup_updated{datid="1",datname="template1"} 0
pg_stat_database_tup_updated{datid="13779",datname="template0"} 0
pg_stat_database_tup_updated{datid="13780",datname="postgres"} 0
pg_stat_database_tup_updated{datid="16384",datname="circle_test"} 0

Edit: Tested with pg15 as well, seems to be ok.
Edit2: Ran the release docker container with pg15 and it seems fine

[Sticksman]

However I do see that in the newest build we might skip some metrics due to the stats_reset column being null which we should account for.

[Sticksman]

The debug logs do show the problem. I don't know why your logs don't include it. I spun up postgres locally with the exporter log level set to debug and I have these logs:

This is only in the latest build, not 0.13.2 which is what our @algchoo is running. I'm unclear what the issue with 0.13.2 is since it doesn't yet have the code skipping the metrics yet.

[algchoo]

The testing I've done has been against containers in k8s, rather than a local docker setup. Using docker-compose I'm still running into the same problems.

I'm running Docker Desktop 4.20.1 on MacOS 13.0.1 with an M1 chip and below is what I'm deploying. Is there anything wrong with this, perhaps?

version: "3.9"
services:
  postgres:
    restart: always
    image: postgres:14
    ports:
      - "5432:5432"
    environment:
      - POSTGRES_USER=root
      - POSTGRES_PASSWORD=password
      - POSTGRES_DB=dev
  exporter:
    restart: always
    image: quay.io/prometheuscommunity/postgres-exporter:v0.13.0
    ports: 
      - 9187:9187
    environment:
      - DATA_SOURCE_NAME=postgresql://root:password@postgres:5432/dev?sslmode=disable
    command: --collector.stat_statements --log.level=debug

[Sticksman]

that all looks right. Let me run your docker-compose file and see if I can repro

[Sticksman]

@algchoo try with quay.io/prometheuscommunity/postgres-exporter:v0.13.2 I believe that should fix the problem. v0.13.0 is indeed not emitting those metrics

[algchoo]

PostgreSQL 14 with exporter version 0.13.2 using docker-compose

CONTAINER ID   IMAGE                                                   COMMAND                  CREATED         STATUS         PORTS                    NAMES
9f109a7ae4f0   postgres:14                                             "docker-entrypoint.s…"   3 seconds ago   Up 2 seconds   0.0.0.0:5432->5432/tcp   postgresql-postgres-1
9eee314cf561   quay.io/prometheuscommunity/postgres-exporter:v0.13.2   "/bin/postgres_expor…"   3 seconds ago   Up 2 seconds   0.0.0.0:9187->9187/tcp   postgresql-exporter-1
❯ docker logs -f 9eee314cf561
ts=2023-07-28T22:16:31.824Z caller=main.go:86 level=warn msg="Error loading config" err="Error opening config file \"postgres_exporter.yml\": open postgres_exporter.yml: no such file or directory"
ts=2023-07-28T22:16:31.824Z caller=proc.go:250 msg="Excluded databases" databases=[]
ts=2023-07-28T22:16:31.825Z caller=main.go:142 level=warn msg="Failed to create PostgresCollector" err="dial tcp 172.18.0.3:5432: connect: connection refused"
ts=2023-07-28T22:16:31.826Z caller=tls_config.go:274 level=info msg="Listening on" address=[::]:9187
ts=2023-07-28T22:16:31.826Z caller=tls_config.go:277 level=info msg="TLS is disabled." http2=false address=[::]:9187
9ts=2023-07-28T22:17:00.325Z caller=server.go:74 level=info msg="Established new database connection" fingerprint=postgres:5432
ts=2023-07-28T22:17:00.344Z caller=postgres_exporter.go:594 level=debug msg="Querying PostgreSQL version" server=postgres:5432
ts=2023-07-28T22:17:00.346Z caller=postgres_exporter.go:622 level=info msg="Semantic version changed" server=postgres:5432 from=0.0.0 to=14.8.0
ts=2023-07-28T22:17:00.346Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=replay_location
ts=2023-07-28T22:17:00.346Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=procpid
ts=2023-07-28T22:17:00.346Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=flush_location
ts=2023-07-28T22:17:00.346Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=sent_location
ts=2023-07-28T22:17:00.346Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=pg_xlog_location_diff
ts=2023-07-28T22:17:00.346Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=write_location
ts=2023-07-28T22:17:00.346Z caller=pg_setting.go:35 level=debug msg="Querying pg_setting view" server=postgres:5432
ts=2023-07-28T22:17:00.351Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_replication
ts=2023-07-28T22:17:00.354Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_replication_slots
ts=2023-07-28T22:17:00.355Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_archiver
ts=2023-07-28T22:17:00.367Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_activity
ts=2023-07-28T22:17:00.369Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_database_conflicts
ts=2023-07-28T22:17:00.370Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_locks
ts=2023-07-28T22:20:23.544Z caller=postgres_exporter.go:594 level=debug msg="Querying PostgreSQL version" server=postgres:5432
ts=2023-07-28T22:20:23.544Z caller=pg_setting.go:35 level=debug msg="Querying pg_setting view" server=postgres:5432
ts=2023-07-28T22:20:23.550Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_replication_slots
ts=2023-07-28T22:20:23.553Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_archiver
ts=2023-07-28T22:20:23.565Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_activity
ts=2023-07-28T22:20:23.568Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_database_conflicts
ts=2023-07-28T22:20:23.569Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_locks
ts=2023-07-28T22:20:23.571Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_replication

PostgreSQL 15.3 with exporter 0.13.2 using docker-compose

CONTAINER ID   IMAGE                                                   COMMAND                  CREATED          STATUS          PORTS                    NAMES
acce6d2c4c14   postgres:15.3                                           "docker-entrypoint.s…"   11 seconds ago   Up 10 seconds   0.0.0.0:5432->5432/tcp   postgresql-postgres-1
9d95359eed3d   quay.io/prometheuscommunity/postgres-exporter:v0.13.2   "/bin/postgres_expor…"   11 seconds ago   Up 10 seconds   0.0.0.0:9187->9187/tcp   postgresql-exporter-1
❯ docker logs -f 9d95359eed3d
ts=2023-07-28T22:22:57.807Z caller=main.go:86 level=warn msg="Error loading config" err="Error opening config file \"postgres_exporter.yml\": open postgres_exporter.yml: no such file or directory"
ts=2023-07-28T22:22:57.807Z caller=proc.go:250 msg="Excluded databases" databases=[]
ts=2023-07-28T22:22:57.812Z caller=main.go:142 level=warn msg="Failed to create PostgresCollector" err="dial tcp 172.19.0.3:5432: connect: connection refused"
ts=2023-07-28T22:22:57.812Z caller=tls_config.go:274 level=info msg="Listening on" address=[::]:9187
ts=2023-07-28T22:22:57.812Z caller=tls_config.go:277 level=info msg="TLS is disabled." http2=false address=[::]:9187
ts=2023-07-28T22:23:15.861Z caller=server.go:74 level=info msg="Established new database connection" fingerprint=postgres:5432
ts=2023-07-28T22:23:15.879Z caller=postgres_exporter.go:594 level=debug msg="Querying PostgreSQL version" server=postgres:5432
ts=2023-07-28T22:23:15.880Z caller=postgres_exporter.go:622 level=info msg="Semantic version changed" server=postgres:5432 from=0.0.0 to=15.3.0
ts=2023-07-28T22:23:15.880Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=procpid
ts=2023-07-28T22:23:15.880Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=replay_location
ts=2023-07-28T22:23:15.880Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=sent_location
ts=2023-07-28T22:23:15.880Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=write_location
ts=2023-07-28T22:23:15.880Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=pg_xlog_location_diff
ts=2023-07-28T22:23:15.880Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=flush_location
ts=2023-07-28T22:23:15.880Z caller=pg_setting.go:35 level=debug msg="Querying pg_setting view" server=postgres:5432
ts=2023-07-28T22:23:15.882Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_database_conflicts
ts=2023-07-28T22:23:15.882Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_locks
ts=2023-07-28T22:23:15.883Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_replication
ts=2023-07-28T22:23:15.885Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_replication_slots
ts=2023-07-28T22:23:15.885Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_archiver
ts=2023-07-28T22:23:15.886Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_activity
ts=2023-07-28T22:23:26.921Z caller=postgres_exporter.go:594 level=debug msg="Querying PostgreSQL version" server=postgres:5432
ts=2023-07-28T22:23:26.922Z caller=pg_setting.go:35 level=debug msg="Querying pg_setting view" server=postgres:5432
ts=2023-07-28T22:23:26.932Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_locks
ts=2023-07-28T22:23:26.933Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_replication
ts=2023-07-28T22:23:26.934Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_replication_slots
ts=2023-07-28T22:23:26.934Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_archiver
ts=2023-07-28T22:23:26.934Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_activity
ts=2023-07-28T22:23:26.936Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_database_conflicts

Unfortunately, the results are the same for me with any version of the exporter 0.13.x running against PostgreSQL 14/15. Is there anything specific around configuring PostgreSQL that I may be missing?

[Sticksman]

Did you try hitting the /metrics endpoint? Here's the docker-compose file I used (basically the same except for 0.13.2)

services:
  postgres:
    restart: always
    image: postgres:14
    ports:
      - "5432:5432"
    environment:
      - POSTGRES_USER=root
      - POSTGRES_PASSWORD=password
      - POSTGRES_DB=dev
  exporter:
    restart: always
    image: quay.io/prometheuscommunity/postgres-exporter:v0.13.2
    ports:
      - 9187:9187
    environment:
      - DATA_SOURCE_NAME=postgresql://root:password@postgres:5432/dev?sslmode=disable
    command: --collector.stat_statements --log.level=debug

Here's a sample of the stats emitted

# TYPE pg_stat_database_tup_deleted counter
pg_stat_database_tup_deleted{datid="0",datname="unknown"} 0
pg_stat_database_tup_deleted{datid="1",datname="template1"} 0
pg_stat_database_tup_deleted{datid="13779",datname="template0"} 0
pg_stat_database_tup_deleted{datid="13780",datname="postgres"} 0
pg_stat_database_tup_deleted{datid="16384",datname="dev"} 0
# HELP pg_stat_database_tup_fetched Number of rows fetched by queries in this database
# TYPE pg_stat_database_tup_fetched counter
pg_stat_database_tup_fetched{datid="0",datname="unknown"} 18
pg_stat_database_tup_fetched{datid="1",datname="template1"} 0
pg_stat_database_tup_fetched{datid="13779",datname="template0"} 0
pg_stat_database_tup_fetched{datid="13780",datname="postgres"} 1481
pg_stat_database_tup_fetched{datid="16384",datname="dev"} 2207
# HELP pg_stat_database_tup_inserted Number of rows inserted by queries in this database
# TYPE pg_stat_database_tup_inserted counter
pg_stat_database_tup_inserted{datid="0",datname="unknown"} 1
pg_stat_database_tup_inserted{datid="1",datname="template1"} 0
pg_stat_database_tup_inserted{datid="13779",datname="template0"} 0
pg_stat_database_tup_inserted{datid="13780",datname="postgres"} 0
pg_stat_database_tup_inserted{datid="16384",datname="dev"} 0
# HELP pg_stat_database_tup_returned Number of rows returned by queries in this database
# TYPE pg_stat_database_tup_returned counter
pg_stat_database_tup_returned{datid="0",datname="unknown"} 97
pg_stat_database_tup_returned{datid="1",datname="template1"} 0
pg_stat_database_tup_returned{datid="13779",datname="template0"} 0
pg_stat_database_tup_returned{datid="13780",datname="postgres"} 2868
pg_stat_database_tup_returned{datid="16384",datname="dev"} 2367
# HELP pg_stat_database_tup_updated Number of rows updated by queries in this database

Here's a logging sample from the container

ts=2023-07-28T22:13:32.066Z caller=postgres_exporter.go:622 level=info msg="Semantic version changed" server=postgres:5432 from=0.0.0 to=14.8.0
ts=2023-07-28T22:13:32.066Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=write_location
ts=2023-07-28T22:13:32.066Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=replay_location
ts=2023-07-28T22:13:32.066Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=pg_xlog_location_diff
ts=2023-07-28T22:13:32.066Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=flush_location
ts=2023-07-28T22:13:32.066Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=procpid
ts=2023-07-28T22:13:32.066Z caller=postgres_exporter.go:296 level=debug msg="Column is being forced to discard due to version incompatibility" column=sent_location
ts=2023-07-28T22:13:32.066Z caller=pg_setting.go:35 level=debug msg="Querying pg_setting view" server=postgres:5432
ts=2023-07-28T22:13:32.068Z caller=collector.go:194 level=debug msg="collector succeeded" name=stat_user_tables duration_seconds=0.02105875
ts=2023-07-28T22:13:32.069Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_archiver
ts=2023-07-28T22:13:32.070Z caller=collector.go:194 level=debug msg="collector succeeded" name=stat_database duration_seconds=0.022516792
ts=2023-07-28T22:13:32.070Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_activity
ts=2023-07-28T22:13:32.070Z caller=collector.go:194 level=debug msg="collector succeeded" name=replication duration_seconds=0.023129291
ts=2023-07-28T22:13:32.072Z caller=collector.go:194 level=debug msg="collector succeeded" name=statio_user_tables duration_seconds=0.024922625
ts=2023-07-28T22:13:32.073Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_database_conflicts
ts=2023-07-28T22:13:32.073Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_locks
ts=2023-07-28T22:13:32.074Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_stat_replication
ts=2023-07-28T22:13:32.076Z caller=namespace.go:193 level=debug msg="Querying namespace" namespace=pg_replication_slots
ts=2023-07-28T22:13:32.077Z caller=collector.go:194 level=debug msg="collector succeeded" name=database duration_seconds=0.029650667

One thing about the pg_stat_database collector in v0.13.x is that so far it was created without a logger, so that might be contributing to the lack of seeing it in the logs. There's a patch in master with a logger attached (and I should make sure all the other collectors have loggers)

[algchoo]

@Sticksman Yes, I hit the metrics endpoint and while I see output, I don't see the expected pg_stat_database metrics. The screenshot shared shows the results I'm getting when testing on any version of 0.13.x against PG 14/15. I misunderstood how the logger was implemented, so if I were to build the exporter from master I'll have the logger that's attached to the pg_stat_database collector, correct? I think the best next step for me is to get actual log output and see what there is to see.

[Sticksman]

I think it'd probably be a decent next step. I'm going to try blowing away all my containers and seeing if there was a cache on my end that was causing me to show the metrics.

[Sticksman]

I've run into a rather strange situation: I've run your docker-compose file after pruning my containers and I can indeed reproduce the issue. However after going to run the two commands individually:

 docker run -p 5432:5432 -e POSTGRES_DB=dev -e POSTGRES_USER=root -e POSTGRES_PASSWORD=password -d postgres:14

docker run \                                                                                                 
  -p 9187:9187 \
  -e DATA_SOURCE_NAME="postgresql://root:[email protected]:5432/dev?sslmode=disable" \
  quay.io/prometheuscommunity/postgres-exporter:v0.13.2 --collector.stat_statements --log.level=debug

I'm finding no issues. Will try using the docker-compose file with the latest build to see if that changes anything.

[Sticksman]

@algchoo I added a depends_on attribute to your yaml so it now looks like this:

  exporter:
    restart: always
    image: quay.io/prometheuscommunity/postgres-exporter:v0.13.2
    ports:
      - 9187:9187
    environment:
      - DATA_SOURCE_NAME=postgresql://root:password@postgres:5432/dev?sslmode=disable
    command: --collector.stat_statements --log.level=debug
    depends_on:
      - postgres

This fixed the issue and began allowing stat_database elements to correctly . This leads me to believe there's a race condition where starting the exporter before the db can cause collectors not to load. I'll file an issue.

[Sticksman]

@algchoo actually here's the error line in the logs

ts=2023-07-28T22:16:31.825Z caller=main.go:142 level=warn msg="Failed to create PostgresCollector" err="dial tcp 172.18.0.3:5432: connect: connection refused"

[yasirsoleja]

Hello, it appears that as part of this change the server label was dropped from all pg_stat_database metrics. Was this intended?

Currently working on upgrading from an older version and noted that the labels for pg_stat_database are no longer consistent with the labels for built-in metrics. Happy to adjust our configs if it was intentional, but just wanted to clarify as this was a breaking change not mentioned in the release notes.