Extremely slow stop/restart after change settings

[maxtar]

Prerequisites

• I have checked the Wiki and Discussions and found no answer

• I have searched other issues and found no duplicates

• I want to report a bug and not ask a question or ask for help

• I have set up AdGuard Home correctly and configured clients to use it. (Use the Discussions for help with installing and configuring clients.)

Platform (OS and CPU architecture)

Linux, ARMv6

Installation

GitHub releases or script from README

Setup

On one machine

AdGuard Home version

v0.107.38

Action

Steps to reproduce:

1. Open web-admin GUI.
2. Login.
3. Open dns settings.
4. Change something (for example add new upstream server or change response after block).
5. Press save button.

Expected result

Server restarted in 1 minute

Actual result

To see in log the following:

Sep 13 14:01:22 raspbpi AdGuardHome[466]: 2023/09/13 14:01:22.088169 [info] dnsforward: starting reconfiguring server
Sep 13 14:01:22 raspbpi AdGuardHome[466]: 2023/09/13 14:01:22.088350 [info] dnsproxy: stopping dns proxy server
Sep 13 14:10:07 raspbpi AdGuardHome[466]: 2023/09/13 14:10:07.830602 [info] dnsproxy: stopped dns proxy server

Difference between the second and third line 10 minutes!

And after 5 minutesI have did the following command:

Adguard -s restart

And this process took about 3 minutes:

Sep 13 14:15:26 raspbpi AdGuardHome[466]: 2023/09/13 14:15:26.159833 [info] service: stopping: waiting for cleanup
Sep 13 14:15:26 raspbpi AdGuardHome[466]: 2023/09/13 14:15:26.159976 [info] Received signal "terminated"
Sep 13 14:15:26 raspbpi AdGuardHome[466]: 2023/09/13 14:15:26.160094 [info] stopping AdGuard Home
Sep 13 14:15:26 raspbpi AdGuardHome[466]: 2023/09/13 14:15:26.160192 [info] stopping http server...
Sep 13 14:15:26 raspbpi systemd[1]: Stopping AdGuard Home: Network-level blocker...
Sep 13 14:15:31 raspbpi AdGuardHome[466]: 2023/09/13 14:15:31.161237 [error] shutting down http server "ip:80": context deadline exceeded
Sep 13 14:15:31 raspbpi AdGuardHome[466]: 2023/09/13 14:15:31.161368 [info] stopped http server
Sep 13 14:16:56 raspbpi systemd[1]: AdGuardHome.service: State 'stop-sigterm' timed out. Killing.
Sep 13 14:16:56 raspbpi systemd[1]: AdGuardHome.service: Killing process 466 (AdGuardHome) with signal SIGKILL.
Sep 13 14:16:56 raspbpi systemd[1]: AdGuardHome.service: Main process exited, code=killed, status=9/KILL
Sep 13 14:16:56 raspbpi systemd[1]: Stopped AdGuard Home: Network-level blocker.
Sep 13 14:16:56 raspbpi systemd[1]: AdGuardHome.service: Unit entered failed state.
Sep 13 14:16:56 raspbpi systemd[1]: AdGuardHome.service: Failed with result 'timeout'.
Sep 13 14:16:56 raspbpi systemd[1]: Starting AdGuard Home: Network-level blocker...
Sep 13 14:16:56 raspbpi systemd[1]: Started AdGuard Home: Network-level blocker.
Sep 13 14:16:56 raspbpi AdGuardHome[3460]: 2023/09/13 14:16:56 [info] AdGuard Home, version v0.107.38
Sep 13 14:16:56 raspbpi AdGuardHome[3460]: 2023/09/13 14:16:56 [info] service: control action: run
Sep 13 14:16:56 raspbpi AdGuardHome[3460]: 2023/09/13 14:16:56.458357 [info] AdGuard Home, version v0.107.38
Sep 13 14:16:56 raspbpi AdGuardHome[3460]: 2023/09/13 14:16:56.458484 [info] AdGuard Home is running as a service
Sep 13 14:16:56 raspbpi AdGuardHome[3460]: 2023/09/13 14:16:56.519324 [info] tls: using default ciphers
Sep 13 14:16:56 raspbpi AdGuardHome[3460]: 2023/09/13 14:16:56.524000 [info] rlimit_nofile set to 65535
Sep 13 14:16:56 raspbpi AdGuardHome[3460]: 2023/09/13 14:16:56.556802 [info] safesearch default: reset 253 rules
Sep 13 14:16:56 raspbpi AdGuardHome[3460]: 2023/09/13 14:16:56.605723 [info] Initializing auth module: /opt/AdGuardHome/data/sessions.db
Sep 13 14:16:56 raspbpi AdGuardHome[3460]: 2023/09/13 14:16:56.607216 [info] auth: initialized.  users:1  sessions:2
Sep 13 14:16:56 raspbpi AdGuardHome[3460]: 2023/09/13 14:16:56.607439 [info] web: initializing
Sep 13 14:16:56 raspbpi AdGuardHome[3460]: 2023/09/13 14:16:56.895310 [info] dnsproxy: cache: enabled, size 4096 b
Sep 13 14:16:56 raspbpi AdGuardHome[3460]: 2023/09/13 14:16:56.895450 [info] dnsproxy: max goroutines is set to 50
Sep 13 14:16:56 raspbpi AdGuardHome[3460]: 2023/09/13 14:16:56.897208 [info] AdGuard Home is available at the following addresses:
Sep 13 14:16:56 raspbpi AdGuardHome[3460]: 2023/09/13 14:16:56.897232 [info] clients: processing addresses
Sep 13 14:16:56 raspbpi AdGuardHome[3460]: 2023/09/13 14:16:56.897403 [info] go to http://ip:80
Sep 13 14:17:00 raspbpi AdGuardHome[3460]: 2023/09/13 14:17:00.745211 [info] dnsproxy: starting dns proxy server
Sep 13 14:17:00 raspbpi AdGuardHome[3460]: 2023/09/13 14:17:00.745435 [info] The server is configured to refuse ANY requests
Sep 13 14:17:00 raspbpi AdGuardHome[3460]: 2023/09/13 14:17:00.745511 [info] dnsproxy: cache: enabled, size 4194304 b
Sep 13 14:17:00 raspbpi AdGuardHome[3460]: 2023/09/13 14:17:00.745601 [info] dnsproxy: max goroutines is set to 50
Sep 13 14:17:00 raspbpi AdGuardHome[3460]: 2023/09/13 14:17:00.745763 [info] dnsproxy: creating udp server socket ip:53
Sep 13 14:17:00 raspbpi AdGuardHome[3460]: 2023/09/13 14:17:00.746360 [info] dnsproxy: listening to udp://ip:53
Sep 13 14:17:00 raspbpi AdGuardHome[3460]: 2023/09/13 14:17:00.746476 [info] dnsproxy: creating tcp server socket ip:53
Sep 13 14:17:00 raspbpi AdGuardHome[3460]: 2023/09/13 14:17:00.746728 [info] dnsproxy: listening to tcp://ip:53
Sep 13 14:17:00 raspbpi AdGuardHome[3460]: 2023/09/13 14:17:00.747292 [info] dnsproxy: entering udp listener loop on ip:53
Sep 13 14:17:00 raspbpi AdGuardHome[3460]: 2023/09/13 14:17:00.747295 [info] dnsproxy: entering tcp listener loop on ip:53

Additional information and/or screenshots

No response

[Trevnar]

Mine just stops working, I have to unplug my raspberry pie to get to to start. then it just stops again after a few minutes.

[schzhn]

Hello, @maxtar. Sorry for the late response.
It's seems like AdGuardHome takes all this time to write statistics and query log to the disk.
Related #6100

[maxtar]

Hello, @maxtar. Sorry for the late response. It's seems like AdGuardHome takes all this time to write statistics and query log to the disk. Related #6100

Am I right that #6100 was fixed in 0.107.37 version?

[schzhn]

@maxtar, yes, it was.

[maxtar]

Looks like fixed.