--log.level has no effect

[saj]

What did you do?

Set --log.level=warn.

What did you expect to see?

No messages logged at debug level.

What did you see instead? Under which circumstances?

Messages logged at debug level. Under all circumstances.

ts=2021-07-09T16:54:26.061Z caller=log.go:168 level=debug msg="Querying namespace" namespace=pg_stat_user_tables
ts=2021-07-09T16:54:26.088Z caller=log.go:168 level=debug msg="Querying namespace" namespace=pg_stat_activity
ts=2021-07-09T16:54:26.090Z caller=log.go:168 level=debug msg="Querying namespace" namespace=pg_stat_bgwriter

Environment

postgres_exporter version:

postgres_exporter, version 0.10.0 (branch: HEAD, revision: 57719ba53cac428769aaf3c4c0bb742df3cfca98)
  build user:       root@4dcb2c7f1315
  build date:       20210709-11:49:20
  go version:       go1.16.5
  platform:         linux/amd64

This is quay.io/prometheuscommunity/postgres-exporter:v0.10.0.

postgres_exporter flags:

$ docker inspect postgresql-test-exporter | jq '.[0].Args'
[
  "--log.level=warn",
  "--web.listen-address=[::]:9113",
  "--extend.query-path=/exporter/queries.yaml"
]

[saj]

I think this regressed between 0.8.0 and 0.10.0. This commit was made prior to the release of 0.10.0:

be790e1 Switch to go-kit log and enable TLS/basic auth

and I think this reproduces the problem:

package main

import (
	"github.com/go-kit/kit/log/level"
	// "github.com/go-kit/log/level"
	"github.com/prometheus/common/promlog"
)

func main() {
	v := promlog.AllowedLevel{}
	v.Set("warn")
	c := &promlog.Config{Level: &v}
	l := promlog.New(c)
	level.Debug(l).Log("msg", "debug")
	level.Info(l).Log("msg", "info")
	level.Warn(l).Log("msg", "warn")
	level.Error(l).Log("msg", "error")
}

The program above will output:

% go run main.go
ts=2021-07-09T16:58:45.684Z caller=log.go:168 level=debug msg=debug
ts=2021-07-09T16:58:45.684Z caller=log.go:168 level=info msg=info
ts=2021-07-09T16:58:45.684Z caller=log.go:168 level=warn msg=warn
ts=2021-07-09T16:58:45.684Z caller=log.go:168 level=error msg=error

But if we swap those go-kit imports around...

diff --git a/main.go b/main.go
index 297bf8a..faabbb5 100644
--- a/main.go
+++ b/main.go
@@ -1,8 +1,8 @@
 package main
 
 import (
-	"github.com/go-kit/kit/log/level"
-	// "github.com/go-kit/log/level"
+	// "github.com/go-kit/kit/log/level"
+	"github.com/go-kit/log/level"
 	"github.com/prometheus/common/promlog"
 )
 

then we get desired behaviour:

% go run main.go
level=warn ts=2021-07-09T17:00:58.409Z caller=main.go:16 msg=warn
level=error ts=2021-07-09T17:00:58.409Z caller=main.go:17 msg=error

% cat go.mod
module foo

go 1.16

require (
        github.com/go-kit/log v0.1.0
        github.com/prometheus/common v0.29.0
)

I have no idea what is going on with go-kit/kit. Looks like they've moved some stuff around.

[n-rodriguez]

Same issue here :/

[karlism]

Having same issue, in fact not setting any --log.level at all will output debug logs.