Set log level to "warn" but still get info-level "using provided configuration"

[KonradHoeffner]

I set Caddy's log level to warn in Caddyfile but Caddy still prints an info message:

$ docker run --rm -p 80:80 -v $PWD/Caddyfile:/etc/caddy/Caddyfile caddy    
{"level":"info","ts":1693822143.8732903,"msg":"using provided configuration","config_file":"/etc/caddy/Caddyfile","config_adapter":"caddyfile"}
{"level":"warn","ts":1693822143.8740778,"logger":"http.auto_https","msg":"server is listening only on the HTTP port, so no automatic HTTPS will be applied to this server","server_name":"srv1","http_port":80}

Caddyfile

{
    log {
        level warn
    }
}

:80, :443

root * /html

Tested with Docker image version 2.7.4, hash e1e1b7ae170b.
I assume the problem is caused by the message being printed first and then the configuration file is loaded.
Instead it should be reversed, then the config file could successfully suppress the info log message.

[mholt]

The log level config won't take effect until after the config is loaded. I believe these two might be printed before the config has been applied.

I don't know how to load the config before loading it 🙈 (if that's what you mean)

[KonradHoeffner]

No, I mean (pseudocode):

currently

log.info("doing the thing")
loadConfig();

fixed version

loadConfig();
log.info("thing successfully done");

[mholt]

Ah, gotcha. The main reason I haven't done that is because it's more complex to do that. Right now, we just print the one log line and carry on, and if anything goes wrong later, we can easily see what the flow is (which config it used, etc).

If we write logs after, then we have to handle all the contingency cases where errors happen and then write something like "we tried using this config, but..." and do that for all the logs before a config is loaded. I don't know if that makes sense but I've often asked myself the "should logs be in past tense or present tense?" when writing code and I usually settle on present tense because it ends up being a lot less complex in the error handling flows.

Can I ask for a better understanding of why these two logs are a problem, exactly?

[KonradHoeffner]

The log messages are not a critical problem for me, I just try to make my docker compose setups as clean as possible so that any error is easily identified and cannot be lost in the clutter, but if switching it off is not easily done than I can live with it.

[mholt]

I can look into it. But one other concern I just thought of is if something about loading the config is hanging (for example, storage I/O), then there'll be no log messages to give any clue as to what is happening. Whereas now, if something is stuck, it can become clear it's in the loading config phase.

[michealroberts]

@KonradHoeffner Could you try this for me:

{
	log default {
		level warn
	}

       ...
}

All I can say is that it "works for me" ... praying for you ... 🙏

[francislavoie]

@michealroberts the point is that we're emitting logs before the config is loaded right now. Adding that to the config doesn't change anything.

[michealroberts]

@francislavoie Ahhy fair, I read it incorrectly. I though the log level was still giving warnings after being set.

[mholt]

I don't think we're going to revamp all our logs right now; this would potentially be quite a large task; though I do agree we could make improvements, I am not sure if there's actually anything specific to "fix" here (as discussed above).