Log Level not filtering some data

[ricardoper]

Hello,

When I startup this app I see a lot of verbose logs that I not want based on my configuration file:

{
	"version": 2,
	"remoteDnsServers": [
		"1.1.1.1",
		"1.0.0.1",
		"8.8.8.8",
		"8.8.4.4"
	],
	"envs": [
		{
			"name": ""
		}
	],
	"activeEnv": "",
	"webServerPort": 5380,
	"dnsServerPort": 53,
	"defaultDns": true,
	"logLevel": "ERROR",
	"logFile": "console",
	"registerContainerNames": true,
	"hostMachineHostname": "",
	"domain": ""
}

Output:

devs_dns           | 2019/09/18 07:42:51 INFO f=index.go:65 pkg=github.com/mageddo/dns-proxy-server/vendor/github.com/mageddo/go-httpmap m=handle status=registering, path=GET /v1/caches
devs_dns           | 2019/09/18 07:42:51 INFO f=index.go:65 pkg=github.com/mageddo/dns-proxy-server/vendor/github.com/mageddo/go-httpmap m=handle status=registering, path=GET /v1/caches/size
devs_dns           | 2019/09/18 07:42:51 INFO f=index.go:65 pkg=github.com/mageddo/dns-proxy-server/vendor/github.com/mageddo/go-httpmap m=handle status=registering, path=GET /env/active
devs_dns           | 2019/09/18 07:42:51 INFO f=index.go:65 pkg=github.com/mageddo/dns-proxy-server/vendor/github.com/mageddo/go-httpmap m=handle status=registering, path=PUT /env/active
devs_dns           | 2019/09/18 07:42:51 INFO f=index.go:65 pkg=github.com/mageddo/dns-proxy-server/vendor/github.com/mageddo/go-httpmap m=handle status=registering, path=GET /env/
devs_dns           | 2019/09/18 07:42:51 INFO f=index.go:65 pkg=github.com/mageddo/dns-proxy-server/vendor/github.com/mageddo/go-httpmap m=handle status=registering, path=POST /env/
devs_dns           | 2019/09/18 07:42:51 INFO f=index.go:65 pkg=github.com/mageddo/dns-proxy-server/vendor/github.com/mageddo/go-httpmap m=handle status=registering, path=DELETE /env/
devs_dns           | 2019/09/18 07:42:51 INFO f=index.go:65 pkg=github.com/mageddo/dns-proxy-server/vendor/github.com/mageddo/go-httpmap m=handle status=registering, path=GET /hostname/
devs_dns           | 2019/09/18 07:42:51 INFO f=index.go:65 pkg=github.com/mageddo/dns-proxy-server/vendor/github.com/mageddo/go-httpmap m=handle status=registering, path=GET /hostname/find/
devs_dns           | 2019/09/18 07:42:51 INFO f=index.go:65 pkg=github.com/mageddo/dns-proxy-server/vendor/github.com/mageddo/go-httpmap m=handle status=registering, path=POST /hostname/
devs_dns           | 2019/09/18 07:42:51 INFO f=index.go:65 pkg=github.com/mageddo/dns-proxy-server/vendor/github.com/mageddo/go-httpmap m=handle status=registering, path=PUT /hostname/
devs_dns           | 2019/09/18 07:42:51 INFO f=index.go:65 pkg=github.com/mageddo/dns-proxy-server/vendor/github.com/mageddo/go-httpmap m=handle status=registering, path=DELETE /hostname/
devs_dns           | 2019/09/18 07:42:51 INFO f=index.go:65 pkg=github.com/mageddo/dns-proxy-server/vendor/github.com/mageddo/go-httpmap m=handle status=registering, path=GET /
devs_dns           | 2019/09/18 07:42:51 INFO f=index.go:65 pkg=github.com/mageddo/dns-proxy-server/vendor/github.com/mageddo/go-httpmap m=handle status=registering, path=GET /configuration/
devs_dns           | 2019/09/18 07:42:51 INFO f=index.go:65 pkg=github.com/mageddo/dns-proxy-server/vendor/github.com/mageddo/go-httpmap m=handle status=registering, path=DELETE /network/disconnect-containers/
devs_dns           | 2019/09/18 07:42:51.299060 DEBUG f=local.go:40 pkg=github.com/mageddo/dns-proxy-server/events/local m=LoadConfiguration status=success-loaded-file, path=/app/conf/config.json
devs_dns           | 2019/09/18 07:42:51.299134 DEBUG f=local.go:40 pkg=github.com/mageddo/dns-proxy-server/events/local m=LoadConfiguration status=success-loaded-file, path=/app/conf/config.json
devs_dns           | 2019/09/18 07:42:51.299145 WARNING f=log.go:16 pkg=github.com/mageddo/dns-proxy-server/log.init m=0 status=log-level-changed, log-level= 3
devs_dns           | 2019/09/18 07:42:51.299217 DEBUG f=local.go:40 pkg=github.com/mageddo/dns-proxy-server/events/local m=LoadConfiguration status=success-loaded-file, path=/app/conf/config.json

Can you check this?

Best regards,
Ricardo Pereira.

[mageddo]

I'll make some checks, did you notice this regression from some version?

Please check if haven't set MG_LOG_LEVEL env variable cause it has precedence

[ricardoper]

Hello @mageddo,

I don't have that env variable defined.

I always see this logs since I used it (about 4 months), but now I report it because I need cleaner logs.

Best regards,
Ricardo Pereira.

[mageddo]

I see, the question is the log level is changed after some steps, then you will see some logs before the log is changed

[mageddo]

2.18.1 was released fixing the issue, can you check it?

[ricardoper]

Hello @mageddo,

Almost perfect. There is a WARNING line that escapes the filter:

devs_dns           | 2019/09/19 06:20:02.797039 WARNING f=logging.go:85 pkg=github.com/mageddo/dns-proxy-server/vendor/github.com/mageddo/go-logging m=Warningf status=log-level-changed, log-level=3

Thanks for the fast release,
Ricardo Pereira

[mageddo]

unfortunately some logs will output before the program reach the point to change the log level, I think in this you can forward the logs to /dev/null or grep ERROR to filter only errors.

I will close the issue considering it partially fixed as won't be able to fix it completely