Inconsistent debug logging

[esc]

Depending on how the debug logging is configured the debug output changes. Essentially, there are two ways to configure the log level, via config file or via command line switch. Naively, I would expect:

a) that the command line switch takes precedence
b) that the debug output is the same regardless of which method was used

The second assumption does not hold.

Here is an example syslog output when using the command line switch --debug:

Mar 24 15:47:30 isdeblnwl081 yaml_server[3839]: DEBUG: initialized with dir_path=/data/home/vhaenel/gw/yaml-server/config, displayname=None,defaultdata=None
Mar 24 15:47:30 isdeblnwl081 yaml_server[3839]: DEBUG: Reading /data/home/vhaenel/gw/yaml-server/config/00_default.yaml
Mar 24 15:47:30 isdeblnwl081 yaml_server[3839]: DEBUG: Configured with {'loglevel': 'DEBUG', 'port': 8935, 'locations': {'dummy': {'path': '/tmp/'}}}
Mar 24 15:47:30 isdeblnwl081 yaml_server[3839]: WARNING: Must be root to drop privileges!
Mar 24 15:47:30 isdeblnwl081 yaml_server[3839]: INFO: Starting on port 8935 for {'dummy': '/tmp'}

And here the output when setting the loglevel to DEBUG in the config file.:

Mar 24 15:48:19 isdeblnwl081 yaml_server[3954]: WARNING: Must be root to drop privileges!
Mar 24 15:48:19 isdeblnwl081 yaml_server[3954]: INFO: Starting on port 8935 for {'dummy': '/tmp'}

As you can see, in the second case some messages are missing. The problem is that there is a code path that is uses to load the config file and debug logging already happens before the config file is loaded and the setting is available. One can avoid this conceptually by first parsing the command line, then reading the config, then setting the loglevel and then issuing all the log messages one would have liked to issue. The benefit is that you get the same output if everything went well. The downside is that certain log messages are dispatched in a delayed fashion, long after the action they are logging has been completed. This is especially problematic if there are issues during the early stages because we don't get any messages. For example if config file or command line parsing fail.

[snordhausen]

I think this is a pretty neat feature, for exactly the reason you mention: --debug allows you to see debug message while the configuration is getting loaded, e.g. from which directories are searched.

However, I agree that the Configured with .... log message should appear in both cases. It is probably the most interesting one and there's no technical reason to omit it.