AdGuardHome AdGuardHome New Release's 2023

[Khadanja]

That wont capture the USB logs because those are normal syslog transactions. AdGuardHome logs would not be helpful determining if you are experiencing USB troubles. If anything, Adguardhome logs would just fill your current system log with unnecessary chatter. You would be looking for system log entries either before Entware has mounted (e.g. system log entrees that indicate your USB storage has mounted successfully or errors indicated it failed to mount). Or, you would be looking for system logs that indicate a failure to unmount right before reboot. A lack of system log entries showing your USB mounting after reboot may indicate a bigger issue unrelated to AdGuardHome.

If you have verified your Entware is mounted and working on each AdGuardHome failure, then the other cause for AdGuardHome failing to start could be a result of insufficient memory available during the time AdGuardHome was started. (OOM killer got to it before it could start.) AdGuardHome debug logs would only be useful to you if you are making it to this point.

Does this mean anything? See log at 21:49:13

Aug  4 21:49:00 68U custom_script: Running /jffs/scripts/service-event-end (args: start dnsmasq)
Aug  4 21:49:00 68U AdGuardHome[4113]: 2023/08/04 21:49:00.404795 [info] AdGuard Home, version v0.108.0-b.42
Aug  4 21:49:00 68U AdGuardHome[4113]: 2023/08/04 21:49:00.405117 [info] AdGuard Home is running as a service
Aug  4 21:49:00 68U custom_script: Running /jffs/scripts/service-event (args: start logger)
Aug  4 21:49:01 68U AdGuardHome[4113]: 2023/08/04 21:49:01.999766 [info] tls: using default ciphers
Aug  4 21:49:02 68U dnsmasq[4232]: exiting on receipt of SIGTERM
Aug  4 21:49:02 68U AdGuardHome[4113]: 2023/08/04 21:49:02.278532 [info] safesearch default: disabled
Aug  4 21:49:02 68U AdGuardHome[4113]: 2023/08/04 21:49:02.346264 [info] Initializing auth module: /tmp/mnt/Asus/entware/etc/AdGuardHome/data/sessions.db
Aug  4 21:49:02 68U AdGuardHome[4113]: 2023/08/04 21:49:02.354402 [info] auth: initialized.  users:1  sessions:5
Aug  4 21:49:02 68U AdGuardHome[4113]: 2023/08/04 21:49:02.355586 [info] AdGuard Home updates are disabled
Aug  4 21:49:02 68U AdGuardHome[4113]: 2023/08/04 21:49:02.356644 [info] web: initializing
Aug  4 21:49:00 syslogd started: BusyBox v1.25.1
Aug  4 21:49:00 kernel: klogd started: BusyBox v1.25.1 (2023-05-14 12:46:55 EDT)
Aug  4 21:49:00 custom_script: Running /jffs/scripts/service-event-end (args: start logger)
Aug  4 21:49:01 custom_script: Running /jffs/scripts/service-event (args: restart dnsmasq)
Aug  4 21:49:01 S99AdGuardHome[3542]: Started AdGuardHome from S99AdGuardHome[3542].
Aug  4 21:49:02 kernel: klogd: exiting
Aug  4 21:49:02 syslogd exiting
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.364040 [info] dnsproxy: cache: enabled, size 4096 b
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.364241 [info] dnsproxy: max goroutines is set to 300
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.403931 [info] AdGuard Home is available at the following addresses:
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.415179 [info] clients: processing addresses
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.567425 [info] go to http://127.0.0.1:14711
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.568244 [info] go to http://127.0.1.1:14711
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.570905 [info] go to http://47.72.207.189:14711
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.573129 [info] go to http://192.168.1.1:14711
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.574234 [info] go to http://10.8.0.1:14711
Aug  4 21:49:13 68U AdGuardHome[4113]: 2023/08/04 21:49:13.583828 [info] Received signal "interrupt"
Aug  4 21:49:13 68U AdGuardHome[4113]: 2023/08/04 21:49:13.584090 [info] stopping AdGuard Home
Aug  4 21:49:13 68U AdGuardHome[4113]: 2023/08/04 21:49:13.584180 [info] stopping http server...
Aug  4 21:49:13 68U AdGuardHome[4113]: 2023/08/04 21:49:13.635323 [info] service: action run has been done successful

 

[SomeWhereOverTheRainBow]

Does this mean anything? See log at 21:49:13

Aug  4 21:49:00 68U custom_script: Running /jffs/scripts/service-event-end (args: start dnsmasq)
Aug  4 21:49:00 68U AdGuardHome[4113]: 2023/08/04 21:49:00.404795 [info] AdGuard Home, version v0.108.0-b.42
Aug  4 21:49:00 68U AdGuardHome[4113]: 2023/08/04 21:49:00.405117 [info] AdGuard Home is running as a service
Aug  4 21:49:00 68U custom_script: Running /jffs/scripts/service-event (args: start logger)
Aug  4 21:49:01 68U AdGuardHome[4113]: 2023/08/04 21:49:01.999766 [info] tls: using default ciphers
Aug  4 21:49:02 68U dnsmasq[4232]: exiting on receipt of SIGTERM
Aug  4 21:49:02 68U AdGuardHome[4113]: 2023/08/04 21:49:02.278532 [info] safesearch default: disabled
Aug  4 21:49:02 68U AdGuardHome[4113]: 2023/08/04 21:49:02.346264 [info] Initializing auth module: /tmp/mnt/Asus/entware/etc/AdGuardHome/data/sessions.db
Aug  4 21:49:02 68U AdGuardHome[4113]: 2023/08/04 21:49:02.354402 [info] auth: initialized.  users:1  sessions:5
Aug  4 21:49:02 68U AdGuardHome[4113]: 2023/08/04 21:49:02.355586 [info] AdGuard Home updates are disabled
Aug  4 21:49:02 68U AdGuardHome[4113]: 2023/08/04 21:49:02.356644 [info] web: initializing
Aug  4 21:49:00 syslogd started: BusyBox v1.25.1
Aug  4 21:49:00 kernel: klogd started: BusyBox v1.25.1 (2023-05-14 12:46:55 EDT)
Aug  4 21:49:00 custom_script: Running /jffs/scripts/service-event-end (args: start logger)
Aug  4 21:49:01 custom_script: Running /jffs/scripts/service-event (args: restart dnsmasq)
Aug  4 21:49:01 S99AdGuardHome[3542]: Started AdGuardHome from S99AdGuardHome[3542].
Aug  4 21:49:02 kernel: klogd: exiting
Aug  4 21:49:02 syslogd exiting
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.364040 [info] dnsproxy: cache: enabled, size 4096 b
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.364241 [info] dnsproxy: max goroutines is set to 300
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.403931 [info] AdGuard Home is available at the following addresses:
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.415179 [info] clients: processing addresses
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.567425 [info] go to http://127.0.0.1:14711
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.568244 [info] go to http://127.0.1.1:14711
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.570905 [info] go to http://47.72.207.189:14711
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.573129 [info] go to http://192.168.1.1:14711
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.574234 [info] go to http://10.8.0.1:14711
Aug  4 21:49:13 68U AdGuardHome[4113]: 2023/08/04 21:49:13.583828 [info] Received signal "interrupt"
Aug  4 21:49:13 68U AdGuardHome[4113]: 2023/08/04 21:49:13.584090 [info] stopping AdGuard Home
Aug  4 21:49:13 68U AdGuardHome[4113]: 2023/08/04 21:49:13.584180 [info] stopping http server...
Aug  4 21:49:13 68U AdGuardHome[4113]: 2023/08/04 21:49:13.635323 [info] service: action run has been done successful

Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.364040 [info] dnsproxy: cache: enabled, size 4096 b
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.364241 [info] dnsproxy: max goroutines is set to 300
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.403931 [info] AdGuard Home is available at the following addresses:
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.415179 [info] clients: processing addresses
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.567425 [info] go to http://127.0.0.1:14711
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.568244 [info] go to http://127.0.1.1:14711
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.570905 [info] go to http://47.72.207.189:14711
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.573129 [info] go to http://192.168.1.1:14711
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.574234 [info] go to http://10.8.0.1:14711
Aug  4 21:49:13 68U AdGuardHome[4113]: 2023/08/04 21:49:13.583828 [info] Received signal "interrupt"
Aug  4 21:49:13 68U AdGuardHome[4113]: 2023/08/04 21:49:13.584090 [info] stopping AdGuard Home
Aug  4 21:49:13 68U AdGuardHome[4113]: 2023/08/04 21:49:13.584180 [info] stopping http server...
Aug  4 21:49:13 68U AdGuardHome[4113]: 2023/08/04 21:49:13.635323 [info] service: action run has been done successful

So Aug 4 21:49:13 68U AdGuardHome[4113]: 2023/08/04 21:49:13.583828 [info] Received signal "interrupt" indicates that the process is being killed somehow at that particular point in time. I don't know what would be killing it, plus it should have immediately started back up with the Manager script which would have restarted it. I need to see your other system log entries around the time these logs are generated. I should be seeing logs indicating what types of actions are being performed by S99AdGuardHome which is the Manager script. It might just be easier if you submit them in .txt file.

Also, please share the contents of these files

/jffs/scripts/init-start
/jffs/scripts/dnsmasq.postconf
/jffs/scripts/services-stop
/jffs/scripts/service-event-end

 

[Khadanja]

Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.364040 [info] dnsproxy: cache: enabled, size 4096 b
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.364241 [info] dnsproxy: max goroutines is set to 300
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.403931 [info] AdGuard Home is available at the following addresses:
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.415179 [info] clients: processing addresses
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.567425 [info] go to http://127.0.0.1:14711
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.568244 [info] go to http://127.0.1.1:14711
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.570905 [info] go to http://47.72.207.189:14711
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.573129 [info] go to http://192.168.1.1:14711
Aug  4 21:49:06 68U AdGuardHome[4113]: 2023/08/04 21:49:06.574234 [info] go to http://10.8.0.1:14711
Aug  4 21:49:13 68U AdGuardHome[4113]: 2023/08/04 21:49:13.583828 [info] Received signal "interrupt"
Aug  4 21:49:13 68U AdGuardHome[4113]: 2023/08/04 21:49:13.584090 [info] stopping AdGuard Home
Aug  4 21:49:13 68U AdGuardHome[4113]: 2023/08/04 21:49:13.584180 [info] stopping http server...
Aug  4 21:49:13 68U AdGuardHome[4113]: 2023/08/04 21:49:13.635323 [info] service: action run has been done successful

So Aug 4 21:49:13 68U AdGuardHome[4113]: 2023/08/04 21:49:13.583828 [info] Received signal "interrupt" indicates that the process is being killed somehow at that particular point in time. I don't know what would be killing it, plus it should have immediately started back up with the Manager script which would have restarted it. I need to see your other system log entries around the time these logs are generated. It might just be easier if you submit them in .txt file.

Also, please share the contents of these files

/jffs/scripts/init-start
/jffs/scripts/dnsmasq.postconf
/jffs/scripts/services-stop
/jffs/scripts/service-event-end

I'll attach the files to a private message. Wonder why logs have date May 5 in between, any idea?

 

[SomeWhereOverTheRainBow]

I'll attach the files to a private message. Wonder why logs have date May 5 in between, any idea?

Your clock is not getting set.

 

[Khadanja]

Your clock is not getting set.

ntp is enabled so why is clock not getting set? How do you attach files to private message? Can't see option?

 

[SomeWhereOverTheRainBow]

ntp is enabled so why is clock not getting set? How do you attach files to private message? Can't see option?

Even if NTP is enabled, it requires DNS to work correctly. If you are using only unbound as your upstream, this could indicated why your clock is not setting. Unbound requires the clock to be set to work correctly. You need to have another resolver added to your AdGuardHome upstream for resolving the NTP server addresses, or you need to use the IP addresses of the NTP servers so your clock sets directly from their IP address instead of having to first resolve the NTP domain name for the IP address before the clock will sync.

 

[Khadanja]

Even if NTP is enabled, it requires DNS to work correctly. If you are using only unbound as your upstream, this could indicated why your clock is not setting. Unbound requires the clock to be set to work correctly. You need to have another resolver added to your AdGuardHome upstream for resolving the NTP server addresses, or you need to use the IP addresses of the NTP servers so your clock sets directly from their IP address instead of having to first resolve their actual domain name for the IP address.

I'm using unbound & 9.9.9.9 as upstream dns.

 

[SomeWhereOverTheRainBow]

I'm using unbound & 9.9.9.9 as upstream dns.

You could try switching to using only the IP addresses for your NTP servers. see if that fixes your issue. Something tells me your issues reside in NTP not getting set, before unbound is allowed to start. AdGuardHome is simply failing to start becauses Unbound isn't running as early as AdGuardHome is.

 

[SomeWhereOverTheRainBow]

Next time your AGH failed, I need you to collect the output of

pidof AdGuardHome
pidof S99AdGuardHome
pidof Unbound
pidof vpnmgr

From an ssh terminal session. Each one should print a number.

 

[Khadanja]

You could try switching to using only the IP addresses for your NTP servers. see if that fixes your issue. Something tells me your issues reside in NTP not getting set, before unbound is allowed to start. AdGuardHome is simply failing to start becauses Unbound isn't running as early as AdGuardHome is.

In AdGuard upstream DNS or router ntp settings? Tried putting ip address of apple 17.253.66.253 & google 216.239.35.4 ntp servers in Adguard but it won't validate.

 

[Khadanja]

Next time your AGH failed, I need you to collect the output of

pidof AdGuardHome
pidof S99AdGuardHome
pidof Unbound
pidof vpnmgr

From an ssh terminal session. Each one should print a number.

Looks like I've managed to break something while setting ntp server. At the moment internet is partially broken. Can browse this forum for some reason but not all sites.
pidof AdGuardHome 8035
pidof S99AdGuardHome 4286
pidof Unbound returns nothing
pidof vpnmgr returns nothing
Also Syslog shows ### Top of Log File ###

 

[Khadanja]

Looks like I've managed to break something while setting ntp server. At the moment internet is partially broken. Can browse this forum for some reason but not all sites.
pidof AdGuardHome 8035
pidof S99AdGuardHome 4286
pidof Unbound returns nothing
pidof vpnmgr returns nothing
Also Syslog shows ### Top of Log File ###

Now my CPU usage is stuck at 100% for both cores,I have to reboot as internet is partially broken, can't browse but can still post here for some reason.

 

[Khadanja]

Everything running fine after reboot except AdGuardHome. Unbound is running as internet is working & I get this when I run unbound_manager advanced - unbound (pid 2345) is running... uptime: 0 Days, 00:07:36 version: 1.17.1 # Version=v1.13 Martineau update (Date Loaded by unbound_manager Thu Aug 3 09:39:43 NZST 2023)
pidof AdGuardHome nothing
pidof S99AdGuardHome 27332 27326 27321 25242 25239 15769 15765 3793
pidof Unbound returns nothing
pidof vpnmgr returns nothing
syslog still shows only this ### Top of Log File ###

 

[SomeWhereOverTheRainBow]

Everything running fine after reboot except AdGuardHome. Unbound is running as internet is working & I get this when I run unbound_manager advanced - unbound (pid 2345) is running... uptime: 0 Days, 00:07:36 version: 1.17.1 # Version=v1.13 Martineau update (Date Loaded by unbound_manager Thu Aug 3 09:39:43 NZST 2023)
pidof AdGuardHome nothing
pidof S99AdGuardHome 27332 27326 27321 25242 25239 15769 15765 3793
pidof Unbound returns nothing
pidof vpnmgr returns nothing
syslog still shows only this ### Top of Log File ###

here is what I get when I pidof Unbound on my test system.

pidof unbound
46394

When I kill unbound, it returns nothing.

 

[Khadanja]

here is what I get when I pidof Unbound on my test system.

pidof unbound
46394

When I kill unbound, it returns nothing.

Sorry I was putting U instead of u
pidof unbound returns 2345. So currently AdGuard is broken, is there a way to troubleshoot it?

 

[SomeWhereOverTheRainBow]

In AdGuard upstream DNS or router ntp settings? Tried putting ip address of apple 17.253.66.253 & google 216.239.35.4 ntp servers in Adguard but it won't validate.

In your NTP settings on the router. Not in AdGuardHome. Remove anything you did inside AdGuardHome that broke things.

Everything running fine after reboot except AdGuardHome. Unbound is running as internet is working & I get this when I run unbound_manager advanced - unbound (pid 2345) is running... uptime: 0 Days, 00:07:36 version: 1.17.1 # Version=v1.13 Martineau update (Date Loaded by unbound_manager Thu Aug 3 09:39:43 NZST 2023)
pidof AdGuardHome nothing
pidof S99AdGuardHome 27332 27326 27321 25242 25239 15769 15765 3793
pidof Unbound returns nothing
pidof vpnmgr returns nothing
syslog still shows only this ### Top of Log File ###

Can you please share your entire log from /jffs/syslog.log

To be honest, at this point I am at a loss. My directions are not clear and are leading you to break things further. I am afraid I am not going to be able to offer up a solution. My only suggestion is it investigate /jffs/syslog.log and look for log entries that may indicate some kind of problem.

 

[Khadanja]

In your NTP settings on the router. Not in AdGuardHome. Remove anything you did inside AdGuardHome that broke things.


Can you please share your entire log from /jffs/syslog.log

I can't access AdGuardHome interface so opened the .yaml file but those ntp server ip's are not there. Also, /jffs/syslog.log folder is empty!

 

[SomeWhereOverTheRainBow]

I can't access AdGuardHome interface so opened the .yaml file but those ntp server ip's are not there. Also, /jffs/syslog.log folder is empty!
View attachment 52171

Sorry, mine isn't:

/jffs# wc -l < syslog.log
9581

I wont be able to provide any more useful assistance here.

My only suggestion now is to either remove unbound and only run AdGuardHome, or only run unbound, and not AdGuardHome. It is apparent it is too much for your router to handle both on top of anything else you have running.

 

[Khadanja]

Sorry, mine isn't:

/jffs# wc -l < syslog.log
9581

I wont be able to provide any more useful assistance here.

ok thanks for all your help so far. Will try to remove scribe maybe that's doing something funny causing syslog to be empty?

 

[Kingp1n]

ok thanks for all your help so far. Will try to remove scribe maybe that's doing something funny causing syslog to be empty?

Maybe. ...I uninstalled scribe and Unbound and only use AGH with the scripts under my signature without any issues. If problems persist it might be time for a complete reset of router.