Ubuntu
unbound package

  1. Bug #1788622
  2. Comment #1

Comment 1 for bug 1788622

Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

Hi Alexey,
I agree - I can reproduce the error and see just the same.

Bionic - reload hangs and then fails, eventually the service is fully restarted due to the kill after timeout
Cosmic - working fine and reports:

The logs contain a few unrelated warnings as I run it in a container, but one can see the difference. Both logs show
1. install (and start of service)
2. calling systemctl reload

Bionic:
$ journalctl -u unbound
-- Logs begin at Fri 2018-08-10 09:34:15 UTC, end at Fri 2018-08-24 05:21:24 UTC. --
Aug 24 05:19:42 b systemd[1]: unbound.service: Failed to reset devices.list: Operation not permitted
Aug 24 05:19:42 b systemd[1]: Starting Unbound DNS server...
Aug 24 05:19:42 b package-helper[13708]: /var/lib/unbound/root.key does not exist, copying from /usr/share/dns/root.key
Aug 24 05:19:42 b package-helper[13708]: /var/lib/unbound/root.key has content
Aug 24 05:19:42 b package-helper[13708]: success: the anchor is ok
Aug 24 05:19:42 b unbound[13713]: [13713:0] notice: init module 0: subnet
Aug 24 05:19:42 b unbound[13713]: [13713:0] notice: init module 1: validator
Aug 24 05:19:42 b unbound[13713]: [13713:0] notice: init module 2: iterator
Aug 24 05:19:42 b unbound[13713]: [13713:0] info: start of service (unbound 1.6.7).
Aug 24 05:19:42 b systemd[1]: Started Unbound DNS server.
Aug 24 05:19:42 b systemd[1]: unbound.service: Failed to reset devices.list: Operation not permitted
Aug 24 05:19:43 b systemd[1]: unbound.service: Failed to reset devices.list: Operation not permitted
Aug 24 05:19:43 b systemd[1]: unbound.service: Failed to reset devices.list: Operation not permitted
Aug 24 05:19:54 b systemd[1]: Reloading Unbound DNS server.
Aug 24 05:19:54 b unbound[13713]: [13713:0] info: service stopped (unbound 1.6.7).
Aug 24 05:19:54 b unbound-control[13840]: ok
Aug 24 05:19:54 b unbound[13713]: [13713:0] info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting
Aug 24 05:19:54 b unbound[13713]: [13713:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0
Aug 24 05:19:54 b unbound[13713]: [13713:0] notice: Restart of unbound 1.6.7.
Aug 24 05:19:54 b unbound[13713]: [13713:0] notice: init module 0: subnet
Aug 24 05:19:54 b unbound[13713]: [13713:0] notice: init module 1: validator
Aug 24 05:19:54 b unbound[13713]: [13713:0] notice: init module 2: iterator
Aug 24 05:19:54 b unbound[13713]: [13713:0] info: start of service (unbound 1.6.7).
Aug 24 05:21:24 b systemd[1]: unbound.service: State 'stop-sigterm' timed out. Killing.
Aug 24 05:21:24 b systemd[1]: unbound.service: Killing process 13713 (unbound) with signal SIGKILL.
Aug 24 05:21:24 b systemd[1]: unbound.service: Main process exited, code=killed, status=9/KILL
Aug 24 05:21:24 b systemd[1]: unbound.service: Failed with result 'timeout'.
Aug 24 05:21:24 b systemd[1]: Reload failed for Unbound DNS server.
Aug 24 05:21:24 b systemd[1]: unbound.service: Service hold-off time over, scheduling restart.
Aug 24 05:21:24 b systemd[1]: unbound.service: Scheduled restart job, restart counter is at 1.
Aug 24 05:21:24 b systemd[1]: Stopped Unbound DNS server.
Aug 24 05:21:24 b systemd[1]: unbound.service: Failed to reset devices.list: Operation not permitted
Aug 24 05:21:24 b systemd[1]: Starting Unbound DNS server...
Aug 24 05:21:24 b package-helper[13844]: /var/lib/unbound/root.key has content
Aug 24 05:21:24 b package-helper[13844]: success: the anchor is ok
Aug 24 05:21:24 b unbound[13848]: [13848:0] notice: init module 0: subnet
Aug 24 05:21:24 b unbound[13848]: [13848:0] notice: init module 1: validator
Aug 24 05:21:24 b unbound[13848]: [13848:0] notice: init module 2: iterator
Aug 24 05:21:24 b unbound[13848]: [13848:0] info: start of service (unbound 1.6.7).
Aug 24 05:21:24 b systemd[1]: Started Unbound DNS server.

Cosmic:
$ journalctl -u unbound
-- Logs begin at Mon 2018-08-20 13:10:44 UTC, end at Fri 2018-08-24 05:21:58 UTC. --
Aug 24 05:21:25 c systemd[1]: unbound.service: Failed to reset devices.list: Operation not permitted
Aug 24 05:21:25 c systemd[1]: Starting Unbound DNS server...
Aug 24 05:21:25 c package-helper[15671]: /var/lib/unbound/root.key does not exist, copying from /usr/share/dns/root.key
Aug 24 05:21:25 c package-helper[15671]: /var/lib/unbound/root.key has content
Aug 24 05:21:25 c package-helper[15671]: success: the anchor is ok
Aug 24 05:21:25 c unbound[15676]: [15676:0] notice: init module 0: subnet
Aug 24 05:21:25 c unbound[15676]: [15676:0] notice: init module 1: validator
Aug 24 05:21:25 c unbound[15676]: [15676:0] notice: init module 2: iterator
Aug 24 05:21:25 c unbound[15676]: [15676:0] info: start of service (unbound 1.7.3).
Aug 24 05:21:25 c systemd[1]: Started Unbound DNS server.
Aug 24 05:21:25 c systemd[1]: unbound.service: Failed to reset devices.list: Operation not permitted
Aug 24 05:21:26 c systemd[1]: unbound.service: Failed to reset devices.list: Operation not permitted
Aug 24 05:21:26 c systemd[1]: unbound.service: Failed to reset devices.list: Operation not permitted
Aug 24 05:21:58 c systemd[1]: Reloading Unbound DNS server.
Aug 24 05:21:58 c unbound[15676]: [15676:0] info: service stopped (unbound 1.7.3).
Aug 24 05:21:58 c unbound[15676]: [15676:0] info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch, 0 rejected by ip ratelimiting
Aug 24 05:21:58 c unbound[15676]: [15676:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0
Aug 24 05:21:58 c unbound-control[15823]: ok
Aug 24 05:21:58 c unbound[15676]: [15676:0] notice: Restart of unbound 1.7.3.
Aug 24 05:21:58 c unbound[15676]: [15676:0] notice: init module 0: subnet
Aug 24 05:21:58 c unbound[15676]: [15676:0] notice: init module 1: validator
Aug 24 05:21:58 c unbound[15676]: [15676:0] notice: init module 2: iterator
Aug 24 05:21:58 c unbound[15676]: [15676:0] info: start of service (unbound 1.7.3).
Aug 24 05:21:58 c systemd[1]: Reloaded Unbound DNS server.

The linked Diff looks small and SRUable to me.
@@ -, +, @@
 #892914)
---
 daemon/daemon.c | 5 ++++-
 1 file changed, 4 insertions(+), 1 deletion(-)
--- b/daemon/daemon.c
+++ b/daemon/daemon.c
@@ -662,7 +662,10 @@ daemon_fork(struct daemon* daemon)
  log_info("start of service (%s).", PACKAGE_STRING);
  worker_work(daemon->workers[0]);
 #ifdef HAVE_SYSTEMD
- sd_notify(0, "STOPPING=1");
+ if (daemon->workers[0]->need_to_exit)
+ sd_notify(0, "STOPPING=1");
+ else
+ sd_notify(0, "RELOADING=1");
 #endif
  log_info("service stopped (%s).", PACKAGE_STRING);

Yeah we should take a look at that soon, thanks for the report Alexey!