Changing the log level doesn't appear to change the actual log level #241

Closed
opened 2025-12-29 01:24:47 +01:00 by adam · 11 comments
Owner

Originally created by @mannp on GitHub (Mar 21, 2022).

Bug description

Changing the log level doesn't appear to change the actual log level coming from headscale server.

log_level: info or log_level: debug, the level of output remains the same

To Reproduce

Add or change the log level (line 158 in the example config) to log_level: info

Context info

  • Version of headscale used: 0.15
  • Version of tailscale client: 1.22.0
  • OS (e.g. Linux, Mac, Cygwin, WSL, etc.) and version: NixOS Unstable
  • Kernel version: 5.16.12
  • The relevant config parameters you used: log_level: info
  • Log output
2022-03-21T10:56:00Z DBG Sending update request func=scheduledPollWorker machine=nixos-m
2022-03-21T10:56:00Z DBG There has been updates since the last successful update to nixos-m handler=PollNetMapStream last_state_change=1647860157 last_successful_update=1647860150 machine=nixos-m
Originally created by @mannp on GitHub (Mar 21, 2022). **Bug description** Changing the log level doesn't appear to change the actual log level coming from headscale server. log_level: info or log_level: debug, the level of output remains the same **To Reproduce** Add or change the log level (line 158 in the example config) to log_level: info **Context info** - Version of headscale used: 0.15 - Version of tailscale client: 1.22.0 - OS (e.g. Linux, Mac, Cygwin, WSL, etc.) and version: NixOS Unstable - Kernel version: 5.16.12 - The relevant config parameters you used: log_level: info - Log output ``` 2022-03-21T10:56:00Z DBG Sending update request func=scheduledPollWorker machine=nixos-m 2022-03-21T10:56:00Z DBG There has been updates since the last successful update to nixos-m handler=PollNetMapStream last_state_change=1647860157 last_successful_update=1647860150 machine=nixos-m ```
adam added the bug label 2025-12-29 01:24:47 +01:00
adam closed this issue 2025-12-29 01:24:47 +01:00
Author
Owner

@huskyii commented on GitHub (Jun 5, 2022):

Can't reproduce, could you check if HEADSCALE_LOG_LEVEL environment variable is set?

@huskyii commented on GitHub (Jun 5, 2022): Can't reproduce, could you check if HEADSCALE_LOG_LEVEL environment variable is set?
Author
Owner

@mannp commented on GitHub (Jun 6, 2022):

Still present in the latest beta's.

Changed log_level in the config file from INFO to DEBUG and the log on a reboot, still shows INFO;

2022-06-06T10:41:11Z INF listening and serving HTTP on: 0.0.0.0:8080
2022-06-06T10:41:11Z INF listening and serving metrics on: 127.0.0.1:9090

Done an export inside the docker and no, HEADSCALE_LOG_LEVEL does not appear to be set...

@mannp commented on GitHub (Jun 6, 2022): Still present in the latest beta's. Changed log_level in the config file from INFO to DEBUG and the log on a reboot, still shows INFO; ``` 2022-06-06T10:41:11Z INF listening and serving HTTP on: 0.0.0.0:8080 2022-06-06T10:41:11Z INF listening and serving metrics on: 127.0.0.1:9090 ``` Done an export inside the docker and no, HEADSCALE_LOG_LEVEL does not appear to be set...
Author
Owner

@kradalby commented on GitHub (Jun 11, 2022):

I cant seem to reproduce this either, I am using the Nix option for setting log level. Are you using Docker or binary + Nix?

@kradalby commented on GitHub (Jun 11, 2022): I cant seem to reproduce this either, I am using the Nix option for setting log level. Are you using Docker or binary + Nix?
Author
Owner

@mannp commented on GitHub (Jun 11, 2022):

Docker and I am only setting the log_level: info option in the config.yaml file and not via an ENV setting.

@mannp commented on GitHub (Jun 11, 2022): Docker and I am only setting the log_level: info option in the config.yaml file and not via an ENV setting.
Author
Owner

@huskyii commented on GitHub (Jun 11, 2022):

Latest headscale has a hidden debug command dumpConfig, could you try headscale dumpConfig and see if /etc/headscale/config.dump.yaml matches your config?

@huskyii commented on GitHub (Jun 11, 2022): Latest headscale has a hidden debug command `dumpConfig`, could you try `headscale dumpConfig` and see if `/etc/headscale/config.dump.yaml` matches your config?
Author
Owner

@mannp commented on GitHub (Jun 12, 2022):

Latest headscale has a hidden debug command dumpConfig, could you try headscale dumpConfig and see if /etc/headscale/config.dump.yaml matches your config?

Thanks for the info, and I dumped the config and compared, it is the same.

I actually used the dump as the main config.yaml and tried again...with the same outcome.

That said, perhaps it is me misreading the log?

This is a sample of the start of my log, using the dump file as a config, should this be DEBUG or INFO, as it's configured as INFO;

2022-06-12T15:44:05Z INF No private key file at path, creating... path=/config/private.key
2022-06-12T15:44:06Z **DBG** Loading DERPMap from path func=GetDERPMap url=https://controlplane.tailscale.com/derpmap/default
2022-06-12T15:44:06Z INF Setting up a DERPMap update worker frequency=86400000
2022-06-12T15:44:06Z WRN Listening without TLS but ServerURL does not start with http://
2022-06-12T15:44:06Z **INF** listening and serving HTTP on: 0.0.0.0:8080
2022-06-12T15:44:06Z INF listening and serving metrics on: 127.0.0.1:9090
@mannp commented on GitHub (Jun 12, 2022): > Latest headscale has a hidden debug command `dumpConfig`, could you try `headscale dumpConfig` and see if `/etc/headscale/config.dump.yaml` matches your config? Thanks for the info, and I dumped the config and compared, it is the same. I actually used the dump as the main config.yaml and tried again...with the same outcome. That said, perhaps it is me misreading the log? This is a sample of the start of my log, using the dump file as a config, should this be DEBUG or INFO, as it's configured as INFO; ``` 2022-06-12T15:44:05Z INF No private key file at path, creating... path=/config/private.key 2022-06-12T15:44:06Z **DBG** Loading DERPMap from path func=GetDERPMap url=https://controlplane.tailscale.com/derpmap/default 2022-06-12T15:44:06Z INF Setting up a DERPMap update worker frequency=86400000 2022-06-12T15:44:06Z WRN Listening without TLS but ServerURL does not start with http:// 2022-06-12T15:44:06Z **INF** listening and serving HTTP on: 0.0.0.0:8080 2022-06-12T15:44:06Z INF listening and serving metrics on: 127.0.0.1:9090 ```
Author
Owner

@kradalby commented on GitHub (Jun 12, 2022):

If the level is INFO for that log snippet, the I believe the DBG should not be there. Can you try your config outside of docker?

@kradalby commented on GitHub (Jun 12, 2022): If the level is INFO for that log snippet, the I believe the DBG should not be there. Can you try your config outside of docker?
Author
Owner

@juanfont commented on GitHub (Jul 24, 2022):

@mannp we are still unable to replicate this. Can you confirm you are still facing the issue? And if that's the case, could you please try with the latest version (0.16.0-beta7) and share the results?

@juanfont commented on GitHub (Jul 24, 2022): @mannp we are still unable to replicate this. Can you confirm you are still facing the issue? And if that's the case, could you please try with the latest version (`0.16.0-beta7`) and share the results?
Author
Owner

@mannp commented on GitHub (Jul 24, 2022):

@kradalby not easily, but @juanfont I will try on the latest and report back asap (once that server backup is complete today)

That said, it is not causing me any major issues, so am happy to close this and reopen if others come across the issue.

@mannp commented on GitHub (Jul 24, 2022): @kradalby not easily, but @juanfont I will try on the latest and report back asap (once that server backup is complete today) That said, it is not causing me any major issues, so am happy to close this and reopen if others come across the issue.
Author
Owner

@juanfont commented on GitHub (Jul 24, 2022):

@mannp thanks! This is the last issue remaining before releasing 0.16 :)

@juanfont commented on GitHub (Jul 24, 2022): @mannp thanks! This is the last issue remaining before releasing 0.16 :)
Author
Owner

@mannp commented on GitHub (Jul 25, 2022):

@juanfont thank you.

Changing from debug to info in the config.yaml did now change from debug logging to info

2022-07-25T08:14:31Z INF listening and serving HTTP on: 0.0.0.0:8080
2022-07-25T08:14:31Z INF listening and serving metrics on: 127.0.0.1:9090
2022-07-25T08:14:43Z ERR Cannot decode message error="cannot decrypt response" handler=PollNetMap
2022-07-25T08:15:04Z ERR Cannot decode message error="cannot decrypt response" handler=PollNetMap
@mannp commented on GitHub (Jul 25, 2022): @juanfont thank you. Changing from debug to info in the config.yaml did now change from debug logging to info ``` 2022-07-25T08:14:31Z INF listening and serving HTTP on: 0.0.0.0:8080 2022-07-25T08:14:31Z INF listening and serving metrics on: 127.0.0.1:9090 2022-07-25T08:14:43Z ERR Cannot decode message error="cannot decrypt response" handler=PollNetMap 2022-07-25T08:15:04Z ERR Cannot decode message error="cannot decrypt response" handler=PollNetMap ```
Sign in to join this conversation.
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: starred/headscale#241