Bug#921538: Fails to start since upgrade to 1.9.0-1

classic Classic list List threaded Threaded
7 messages Options
Reply | Threaded
Open this post in threaded view
|

Bug#921538: Fails to start since upgrade to 1.9.0-1

Ryan Kavanagh-3
Package: unbound
Version: 1.9.0-1
Severity: grave

Since the upgrade to 1.9.0-1, unbound fails to start. Purging the
package and reinstalling does not fix the issue. The errors seem to be
due to being unable to read various configuration files.

Feb 06 11:01:12 zeta unbound[28647]: [28647:0] error: unable to open /var/lib/unbound/root.key for reading: No such file or directory
Feb 06 11:01:12 zeta package-helper[28648]: [1549468872] unbound-checkconf[28651:0] error: Could not open /etc/unbound//etc/unbound/unbound.conf: No such file or director

----------------------------------------------------------------------
rak@zeta:~$ sudo apt purge unbound && sudo apt install unbound
Reading package lists... Done
Building dependency tree
Reading state information... Done
The following packages were automatically installed and are no longer required:
  apg bmon byobu ccze cmatrix ipsec-tools jp2a libconfuse-common libconfuse2 libipe7.2.7 moreutils pastebinit python-newt screen speedometer tree unbound-anchor
Use 'sudo apt autoremove' to remove them.
The following packages will be REMOVED:
  unbound*
0 upgraded, 0 newly installed, 1 to remove and 111 not upgraded.
After this operation, 4,286 kB disk space will be freed.
Do you want to continue? [Y/n]
(Reading database ... 450489 files and directories currently installed.)
Removing unbound (1.9.0-1) ...
Processing triggers for man-db (2.8.5-1) ...
(Reading database ... 450457 files and directories currently installed.)
Purging configuration files for unbound (1.9.0-1) ...
insserv: There is a loop between service sendsigs and racoon if stopped
insserv:  loop involving service racoon at depth 3
insserv:  loop involving service sendsigs at depth 2
insserv:  loop involving service bluetooth at depth 1
insserv:  loop involving service rsyslog at depth 4
insserv:  loop involving service avahi at depth 2
Processing triggers for systemd (240-5) ...
Reading package lists... Done
Building dependency tree
Reading state information... Done
The following packages were automatically installed and are no longer required:
  apg bmon byobu ccze cmatrix ipsec-tools jp2a libconfuse-common libconfuse2 libipe7.2.7 moreutils pastebinit python-newt screen speedometer tree
Use 'sudo apt autoremove' to remove them.
The following NEW packages will be installed:
  unbound
0 upgraded, 1 newly installed, 0 to remove and 111 not upgraded.
Need to get 0 B/795 kB of archives.
After this operation, 4,286 kB of additional disk space will be used.
Selecting previously unselected package unbound.
(Reading database ... 450450 files and directories currently installed.)
Preparing to unpack .../unbound_1.9.0-1_amd64.deb ...
Unpacking unbound (1.9.0-1) ...
Setting up unbound (1.9.0-1) ...
Created symlink /etc/systemd/system/multi-user.target.wants/unbound.service → /lib/systemd/system/unbound.service.
Created symlink /etc/systemd/system/unbound.service.wants/unbound-resolvconf.service → /lib/systemd/system/unbound-resolvconf.service.
Job for unbound.service failed because the control process exited with error code.
See "systemctl status unbound.service" and "journalctl -xe" for details.
insserv: There is a loop between service sendsigs and racoon if stopped
insserv:  loop involving service racoon at depth 3
insserv:  loop involving service sendsigs at depth 2
insserv:  loop involving service bluetooth at depth 1
insserv:  loop involving service rsyslog at depth 4
insserv:  loop involving service avahi at depth 2
Job for unbound.service failed because the control process exited with error code.
See "systemctl status unbound.service" and "journalctl -xe" for details.
invoke-rc.d: initscript unbound, action "start" failed.
● unbound.service - Unbound DNS server
   Loaded: loaded (/lib/systemd/system/unbound.service; enabled; vendor preset: enabled)
   Active: activating (auto-restart) (Result: exit-code) since Wed 2019-02-06 11:01:07 EST; 7ms ago
     Docs: man:unbound(8)
  Process: 28299 ExecStartPre=/usr/lib/unbound/package-helper chroot_setup (code=exited, status=0/SUCCESS)
  Process: 28333 ExecStartPre=/usr/lib/unbound/package-helper root_trust_anchor_update (code=exited, status=0/SUCCESS)
  Process: 28374 ExecStart=/usr/sbin/unbound -d $DAEMON_OPTS (code=exited, status=1/FAILURE)
 Main PID: 28374 (code=exited, status=1/FAILURE)

Feb 06 11:01:07 zeta systemd[1]: Failed to start Unbound DNS server.
Feb 06 11:01:07 zeta unbound[28374]: [28374:0] fatal error: failed to setup modules
Processing triggers for systemd (240-5) ...
Processing triggers for man-db (2.8.5-1) ...
----------------------------------------------------------------------


----------------------------------------------------------------------
rak@zeta:~$ systemctl status unbound.service
● unbound.service - Unbound DNS server
   Loaded: loaded (/lib/systemd/system/unbound.service; enabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Wed 2019-02-06 11:01:12 EST; 3min 43s ago
     Docs: man:unbound(8)
  Process: 28640 ExecStartPre=/usr/lib/unbound/package-helper chroot_setup (code=exited, status=0/SUCCESS)
  Process: 28643 ExecStartPre=/usr/lib/unbound/package-helper root_trust_anchor_update (code=exited, status=0/SUCCESS)
  Process: 28647 ExecStart=/usr/sbin/unbound -d $DAEMON_OPTS (code=exited, status=1/FAILURE)
 Main PID: 28647 (code=exited, status=1/FAILURE)
----------------------------------------------------------------------

----------------------------------------------------------------------
rak@zeta:~$ sudo journalctl -xe
Feb 06 11:01:12 zeta systemd[1]: Starting Unbound DNS server...
-- Subject: A start job for unit unbound.service has begun execution
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- A start job for unit unbound.service has begun execution.
--
-- The job identifier is 27673.
Feb 06 11:01:12 zeta package-helper[28643]: /var/lib/unbound/root.key has content
Feb 06 11:01:12 zeta package-helper[28643]: success: the anchor is ok
Feb 06 11:01:12 zeta unbound[28647]: [28647:0] notice: init module 0: subnet
Feb 06 11:01:12 zeta unbound[28647]: [28647:0] notice: init module 1: validator
Feb 06 11:01:12 zeta unbound[28647]: [28647:0] error: unable to open /var/lib/unbound/root.key for reading: No such file or directory
Feb 06 11:01:12 zeta unbound[28647]: [28647:0] error: error reading auto-trust-anchor-file: /var/lib/unbound/root.key
Feb 06 11:01:12 zeta unbound[28647]: [28647:0] error: validator: error in trustanchors config
Feb 06 11:01:12 zeta systemd[1]: unbound.service: Main process exited, code=exited, status=1/FAILURE
-- Subject: Unit process exited
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- An ExecStart= process belonging to unit unbound.service has exited.
--
-- The process' exit code is 'exited' and its exit status is 1.
Feb 06 11:01:12 zeta unbound[28647]: [28647:0] error: validator: could not apply configuration settings.
Feb 06 11:01:12 zeta systemd[1]: unbound.service: Failed with result 'exit-code'.
-- Subject: Unit failed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- The unit unbound.service has entered the 'failed' state with result 'exit-code'.
Feb 06 11:01:12 zeta unbound[28647]: [28647:0] error: module init for module validator failed
Feb 06 11:01:12 zeta unbound[28647]: [28647:0] fatal error: failed to setup modules
Feb 06 11:01:12 zeta systemd[1]: Failed to start Unbound DNS server.
-- Subject: A start job for unit unbound.service has failed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- A start job for unit unbound.service has finished with a failure.
--
-- The job identifier is 27673 and the job result is failed.
Feb 06 11:01:12 zeta systemd[1]: Started Unbound DNS server via resolvconf.
-- Subject: A start job for unit unbound-resolvconf.service has finished successfully
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- A start job for unit unbound-resolvconf.service has finished successfully.
--
-- The job identifier is 27748.
Feb 06 11:01:12 zeta package-helper[28648]: [1549468872] unbound-checkconf[28651:0] error: Could not open /etc/unbound//etc/unbound/unbound.conf: No such file or director
Feb 06 11:01:12 zeta systemd[1]: unbound.service: Service RestartSec=100ms expired, scheduling restart.
Feb 06 11:01:12 zeta systemd[1]: unbound.service: Scheduled restart job, restart counter is at 8.
-- Subject: Automatic restarting of a unit has been scheduled
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- Automatic restarting of the unit unbound.service has been scheduled, as the result for
-- the configured Restart= setting for the unit.
Feb 06 11:01:12 zeta systemd[1]: Stopping Unbound DNS server via resolvconf...
-- Subject: A stop job for unit unbound-resolvconf.service has begun execution
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- A stop job for unit unbound-resolvconf.service has begun execution.
--
-- The job identifier is 27897.
Feb 06 11:01:12 zeta systemd[1]: unbound-resolvconf.service: Succeeded.
-- Subject: Unit succeeded
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- The unit unbound-resolvconf.service has successfully entered the 'dead' state.
Feb 06 11:01:12 zeta systemd[1]: Stopped Unbound DNS server via resolvconf.
-- Subject: A stop job for unit unbound-resolvconf.service has finished
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- A stop job for unit unbound-resolvconf.service has finished.
--
-- The job identifier is 27897 and the job result is done.
Feb 06 11:01:12 zeta systemd[1]: Stopped Unbound DNS server.
-- Subject: A stop job for unit unbound.service has finished
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- A stop job for unit unbound.service has finished.
--
-- The job identifier is 27822 and the job result is done.
Feb 06 11:01:12 zeta systemd[1]: unbound.service: Start request repeated too quickly.
Feb 06 11:01:12 zeta systemd[1]: unbound.service: Failed with result 'exit-code'.
-- Subject: Unit failed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- The unit unbound.service has entered the 'failed' state with result 'exit-code'.
Feb 06 11:01:12 zeta systemd[1]: Failed to start Unbound DNS server.
-- Subject: A start job for unit unbound.service has failed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- A start job for unit unbound.service has finished with a failure.
--
-- The job identifier is 27822 and the job result is failed.
Feb 06 11:01:12 zeta systemd[1]: unbound-resolvconf.service: Start request repeated too quickly.
Feb 06 11:01:12 zeta systemd[1]: unbound-resolvconf.service: Failed with result 'start-limit-hit'.
-- Subject: Unit failed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- The unit unbound-resolvconf.service has entered the 'failed' state with result 'start-limit-hit'.
Feb 06 11:01:12 zeta systemd[1]: Failed to start Unbound DNS server via resolvconf.
-- Subject: A start job for unit unbound-resolvconf.service has failed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
--
-- A start job for unit unbound-resolvconf.service has finished with a failure.
--
-- The job identifier is 27897 and the job result is failed.


-- System Information:
Debian Release: buster/sid
  APT prefers unstable-debug
  APT policy: (500, 'unstable-debug'), (500, 'unstable'), (1, 'experimental-debug'), (1, 'experimental')
Architecture: amd64 (x86_64)
Foreign Architectures: i386

Kernel: Linux 4.19.0-2-amd64 (SMP w/4 CPU cores)
Kernel taint flags: TAINT_PROPRIETARY_MODULE, TAINT_OOT_MODULE, TAINT_UNSIGNED_MODULE
Locale: LANG=en_CA.UTF-8, LC_CTYPE=en_CA.UTF-8 (charmap=UTF-8) (ignored: LC_ALL set to en_CA.UTF-8), LANGUAGE=en_CA.UTF-8 (charmap=UTF-8) (ignored: LC_ALL set to en_CA.UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled

Versions of packages unbound depends on:
ii  adduser         3.118
ii  dns-root-data   2018091102
ii  libc6           2.28-6
ii  libevent-2.1-6  2.1.8-stable-4
ii  libfstrm0       0.4.0-1
ii  libprotobuf-c1  1.3.1-1+b1
ii  libpython3.7    3.7.2-2
ii  libssl1.1       1.1.1a-1
ii  libsystemd0     240-5
ii  lsb-base        10.2018112800
ii  openssl         1.1.1a-1
ii  unbound-anchor  1.9.0-1

unbound recommends no packages.

Versions of packages unbound suggests:
ii  apparmor  2.13.2-7

-- no debconf information

--
|)|/  Ryan Kavanagh      | GPG: 4E46 9519 ED67 7734 268F
|\|\  https://rak.ac     |      BD95 8F7B F8FC 4A11 C97A

signature.asc (1K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Bug#921538: Fails to start since upgrade to 1.9.0-1

Simon Deziel-2
Here is a merge request [*] to disable chroot'ing again like it has been
since version 1.0.0-3

Regards,
Simon

*: https://salsa.debian.org/dns-team/unbound/merge_requests/3


signature.asc (849 bytes) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Bug#921538: Fails to start since upgrade to 1.9.0-1

Trout, Diane E.
In reply to this post by Ryan Kavanagh-3
>
> It seems like chroot'ing to /etc/unbound is attempted. To workaround
you
> can try this:
>
> cat << EOF > /etc/unbound/unbound.conf.d/chroot.conf
> server:
>   chroot: ""
> EOF
> service unbound restart

This fix worked for me.

Reply | Threaded
Open this post in threaded view
|

Bug#921538: Fails to start since upgrade to 1.9.0-1

Ryan Kavanagh-3
In reply to this post by Ryan Kavanagh-3
Hi Simon,

I too can confirm that disabling chroot'ing works.

Best,
Ryan

--
|)|/  Ryan Kavanagh      | GPG: 4E46 9519 ED67 7734 268F
|\|\  https://rak.ac     |      BD95 8F7B F8FC 4A11 C97A

signature.asc (1K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Bug#921538: Fails to start since upgrade to 1.9.0-1

Ondra Kudlík
In reply to this post by Ryan Kavanagh-3
Chroot workaround is working for me too. It should probably be uploaded
as soon as possible to save more networks :)

Anyway in the long term would it be better to have chroot setup
automatically again? I found out that it was working before, at least
some work was done in #579622 for auto support.

Cheers

--
Kepi

signature.asc (847 bytes) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Bug#921538: Fails to start since upgrade to 1.9.0-1

Simon Deziel-2
On 2019-02-08 7:26 a.m., Kepi wrote:
> Chroot workaround is working for me too.

Good.

> Anyway in the long term would it be better to have chroot setup
> automatically again? I found out that it was working before, at least
> some work was done in #579622 for auto support.

The auto-chroot setup was broken with the (welcomed) move to systemd
notify. I have a working PoC to restore the functionality that I'll
submit soon as another merge request.

Regards,
Simon


signature.asc (849 bytes) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Bug#921538: Fails to start since upgrade to 1.9.0-1

Simon Deziel-2
In reply to this post by Ryan Kavanagh-3
On 2019-02-09 8:28 p.m., Robert Edmonds wrote:
> Probably it's better to use the --with-chroot-dir= argument to configure
> rather than directly patching the source to change the default.

Indeed and that's what's being proposed in the merge request.

Regards,
Simon