AdguardTeam / AdGuardHome

Network-wide ads & trackers blocking DNS server
https://adguard.com/adguard-home.html
GNU General Public License v3.0
25.51k stars 1.83k forks source link

Have "-l syslog" and "log_localtime=true" honor the env TZ data or "/etc/localtime" #4207

Open jumpsmm7 opened 2 years ago

jumpsmm7 commented 2 years ago

Have a question or an idea? Please search it on our forum to make sure it was not yet asked. If you cannot find what you had in mind, please submit it here.

Prerequisites

Please answer the following questions for yourself before submitting an issue. YOU MAY DELETE THE PREREQUISITES SECTION.

Problem Description

When both "-l syslog" and "log_localtime=true" , system log does not properly parse the available TZ data for the correct time zone. Instead, UTC is used. Here is an example of what the problem looks like.

Jan 26 00:38:41 RT-AX88U-C7C0 dnsmasq[5042]: using 11 more local addresses Jan 26 00:38:41 RT-AX88U-C7C0 custom_script: Running /jffs/scripts/service-event-end (args: restart dnsmasq) Jan 26 05:38:42 RT-AX88U-C7C0 AdGuardHome[4920]: 2022/01/26 05:38:42.244226 [info] Starting the DNS proxy server Jan 26 05:38:42 RT-AX88U-C7C0 AdGuardHome[4920]: 2022/01/26 05:38:42.244345 [info] Ratelimit is enabled and set to 20 rps Jan 26 05:38:42 RT-AX88U-C7C0 AdGuardHome[4920]: 2022/01/26 05:38:42.244367 [info] The server is configured to refuse ANY requests Jan 26 05:38:42 RT-AX88U-C7C0 AdGuardHome[4920]: 2022/01/26 05:38:42.244385 [info] DNS cache is enabled Jan 26 05:38:42 RT-AX88U-C7C0 AdGuardHome[4920]: 2022/01/26 05:38:42.244492 [info] MaxGoroutines is set to 300 Jan 26 05:38:42 RT-AX88U-C7C0 AdGuardHome[4920]: 2022/01/26 05:38:42.244533 [info] Creating the UDP server socket Jan 26 05:38:42 RT-AX88U-C7C0 AdGuardHome[4920]: 2022/01/26 05:38:42.244700 [info] Listening to udp://[::]:53 Jan 26 05:38:42 RT-AX88U-C7C0 AdGuardHome[4920]: 2022/01/26 05:38:42.244720 [info] Creating a TCP server socket Jan 26 05:38:42 RT-AX88U-C7C0 AdGuardHome[4920]: 2022/01/26 05:38:42.244810 [info] Listening to tcp://[::]:53 Jan 26 05:38:42 RT-AX88U-C7C0 AdGuardHome[4920]: 2022/01/26 05:38:42.245790 [info] Entering the tcp listener loop on [::]:53 Jan 26 05:38:42 RT-AX88U-C7C0 AdGuardHome[4920]: 2022/01/26 05:38:42.246830 [info] Entering the UDP listener loop on [::]:53 Jan 26 00:39:05 RT-AX88U-C7C0 rc_service: httpd 1321:notify_rc start_scmerlingetaddonpages;start_scmerlingetcronjobs Jan 26 00:39:05 RT-AX88U-C7C0 custom_script: Running /jffs/scripts/service-event (args: start scmerlingetaddonpages) Jan 26 00:39:05 RT-AX88U-C7C0 custom_script: Running /jffs/scripts/service-event-end (args: start scmerlingetaddonpages) Jan 26 00:39:05 RT-AX88U-C7C0 custom_script: Running /jffs/scripts/service-event (args: start scmerlingetcronjobs) Jan 26 00:39:05 RT-AX88U-C7C0 custom_script: Running /jffs/scripts/service-event-end (args: start scmerlingetcronjobs) Jan 26 00:39:07 RT-AX88U-C7C0 rc_service: httpd 1321:notify_rc start_addon_settings;start_connmoncustomactionlist;st

Proposed Solution

The solution to the problem would for the GO, or what ever mechanisms AdGuardHome uses, to be able to properly parse the environment TZ data. For example, export TZ=$(cat /etc/TZ) or have AdGuardHome parse for /etc/localtime.

Alternatives Considered

Here is an example from the go.dev source.

https://go.dev/src/time/zoneinfo_unix.go

ainar-g commented 2 years ago

Hello. There isn't a settings called local_timezone in AdGuard Home. Did you mean log_localtime? If so, it's a setting for the file-based logging and is ignored when syslog is used.

By default, AdGuard Home uses local time, so make sure that your TZ variable is properly set in your scripts.

jumpsmm7 commented 2 years ago

Hello. There isn't a settings called local_timezone in AdGuard Home. Did you mean log_localtime? If so, it's a setting for the file-based logging and is ignored when syslog is used.

By default, AdGuard Home uses local time, so make sure that your TZ variable is properly set in your scripts.

Yes log_localtime. My bad. I was tired typing this up. I will correct to reflect the right nomenclature.

jumpsmm7 commented 2 years ago

Hello. There isn't a settings called local_timezone in AdGuard Home. Did you mean log_localtime? If so, it's a setting for the file-based logging and is ignored when syslog is used.

By default, AdGuard Home uses local time, so make sure that your TZ variable is properly set in your scripts.

So in this scenario, the TZ data has been exported( and correct) , but AdGuardHome does not find it, instead when logging, it uses the UTC time. While the UTC time and date it uses is correct, it would be nice to display the system log messages in local time reflecting the TZ data or /etc/localtime. This is a feature request, since apparently AdGuardHome does not or is reluctant to do such. I wouldn't say this is a bug because I am not sure AdGuardHome has been fully configured to do this yet.

To give you more info on how the TZ data is displayed,

EST5DST,M3.2.0/2,M11.1.0/2

is how it appears. This would represent an Eastern timezone in the united states. I am not sure AdGuardHome can interpret this.

Maybe a feature would be to provide away to point AdGuardHome to this value, similar to how you have away to specify -l syslog.

ainar-g commented 2 years ago

Ah, thanks, I see the issue now. A workaround is to set the TZ variable to the tz database name of the zone. For example, TZ='America/New_York'.

I'll investigate if this can be fixed.

jumpsmm7 commented 2 years ago

Ah, thanks, I see the issue now. A workaround is to set the TZ variable to the tz database name of the zone. For example, TZ='America/New_York'.

I'll investigate if this can be fixed.

I figured this was the case because that is how it was done when setting adguardhome docker, but the difference here is it is done on a pure Linux platform that reports timezone in the earlier mentioned format.

ainar-g commented 2 years ago

@jumpsmm7, I've done some experimenting and filed golang/go#50863. Seems like a bug / absence of functionality in the Go standard library to me, but I may be wrong.

jumpsmm7 commented 2 years ago

@jumpsmm7, I've done some experimenting and filed golang/go#50863. Seems like a bug / absence of functionality in the Go standard library to me, but I may be wrong.

Dnscrypt proxy 2 devs had a similar issue with their dlog.go awhile back here is a link to what they did to resolve the issue. I hope this helps.

https://github.com/DNSCrypt/dnscrypt-proxy/issues/57

jumpsmm7 commented 2 years ago

@ainar-g I came up with a temporary solution. The POSIX system will allow me to point using env variable to the TZ="/etc/localtime" , I just have to let users configure their localtime themselves.

dave14305 commented 2 years ago

@ainar-g I came up with a temporary solution. The POSIX system will allow me to point using env variable to the TZ="/etc/localtime" , I just have to let users configure their localtime themselves.

The router already sets /etc/localtime. Update the startup script to unset TZ before launching AGH and see if Go gets the correct timezone info (after undoing your localtime workaround).

jumpsmm7 commented 2 years ago

@dave14305

I tried this once, but found /etc/localtime not set still. I will try again. The outputs show that it did not work @RT-AX88U-C7C0:/tmp/home/root# /usr/bin/tail -f /opt/var/log/AdGuardHome.log 2022/02/08 04:50:03.532740 [info] Ratelimit is enabled and set to 20 rps 2022/02/08 04:50:03.532753 [info] The server is configured to refuse ANY requests 2022/02/08 04:50:03.532767 [info] DNS cache is enabled 2022/02/08 04:50:03.532789 [info] MaxGoroutines is set to 300 2022/02/08 04:50:03.532825 [info] Creating the UDP server socket 2022/02/08 04:50:03.533002 [info] Listening to udp://[::]:53 2022/02/08 04:50:03.533018 [info] Creating a TCP server socket 2022/02/08 04:50:03.533102 [info] Listening to tcp://[::]:53 2022/02/08 04:50:03.533625 [info] Entering the tcp listener loop on [::]:53 2022/02/08 04:50:03.534823 [info] Entering the UDP listener loop on [::]:53

Looks like you are right. I will add this in.

one thing though, I actually don't have to unset TZ if I am directly defining it inside the env variable.

ainar-g commented 2 years ago

@jumpsmm7, sorry, but I don't quite get it. What was the solution? Unsetting TZ or something else?

jumpsmm7 commented 2 years ago

@jumpsmm7, sorry, but I don't quite get it. What was the solution? Unsetting TZ or something else?

In regards to options available, the unset TZ option is not needed since the argument env can be directly passed stating env TZ=/etc/localtime, otherwise unsetting the TZ would allow adguardhome to find the TZ value if it exist at TZ=/etc/localtime since unsetting TZ would clear the routers default TZ declarations.

ainar-g commented 2 years ago

@jumpsmm7, @dave14305, thanks to you both! We'll document that solution somewhere in the Wiki. I'll leave the issue open until we do that.