Bug#1002640: bind9 won't start after upgrading from 9.11 - "the working directory is not writable"
Robert Waldner
Version: 1:9.16.22-1~deb11u1
Severity: important
Dear Maintainers,
I upgraded my nameserver from buster to bullseye, afterwards named wouldn't start anymore.
Looking at syslog, the relevant part seems to be:
...
Dec 26 11:36:01 fsck named[128029]: configuring command channel from '/etc/bind/rndc.key'
Dec 26 11:36:01 fsck named[128029]: command channel listening on 127.0.0.1#953
Dec 26 11:36:01 fsck named[128029]: configuring command channel from '/etc/bind/rndc.key'
Dec 26 11:36:01 fsck named[128029]: command channel listening on ::1#953
Dec 26 11:36:01 fsck named[128029]: the working directory is not writable
^^^^^^^^^^^^^^^^^
Dec 26 11:36:01 fsck named[128029]: loading configuration: permission denied
Dec 26 11:36:01 fsck named[128029]: exiting (due to fatal error)
Dec 26 11:36:01 fsck systemd[1]: named.service: Main process exited, code=exited, status=1/FAILURE
Dec 26 11:36:01 fsck systemd[1]: named.service: Failed with result 'exit-code'.
Note that this is straight from systemd trying to start it.
Running named as `named -g -u bind` got the same result (CWD: /home/myuser).
But! starting it manually with a CWD that's writable by group bind (eg. `cd /etc/bind; named -g -u bind`) works:
...
26-Dec-2021 11:44:10.434 configuring command channel from '/etc/bind/rndc.key'
26-Dec-2021 11:44:10.434 command channel listening on 127.0.0.1#953
26-Dec-2021 11:44:10.434 configuring command channel from '/etc/bind/rndc.key'
26-Dec-2021 11:44:10.434 command channel listening on ::1#953
26-Dec-2021 11:44:10.434 not using config file logging statement for logging due to -g option
26-Dec-2021 11:44:10.434 zone 10.in-addr.arpa/IN: loaded serial 2002041301
...
Now this wouldn't be a problem is systemd could start named, but it can't:
root@fsckv2:/etc/bind# systemctl start named
root@fsckv2:/etc/bind# systemctl status named
● named.service - BIND Domain Name Server
Loaded: loaded (/lib/systemd/system/named.service; enabled; vendor preset: enabled)
Active: failed (Result: exit-code) since Sun 2021-12-26 11:46:23 CET; 1s ago
Docs: man:named(8)
Process: 130605 ExecStart=/usr/sbin/named -f $OPTIONS (code=exited, status=1/FAILURE)
Main PID: 130605 (code=exited, status=1/FAILURE)
CPU: 51ms
Dec 26 11:46:23 fsckv2 systemd[1]: named.service: Scheduled restart job, restart counter is at 5.
Dec 26 11:46:23 fsckv2 systemd[1]: Stopped BIND Domain Name Server.
Dec 26 11:46:23 fsckv2 systemd[1]: named.service: Start request repeated too quickly.
Dec 26 11:46:23 fsckv2 systemd[1]: named.service: Failed with result 'exit-code'.
Dec 26 11:46:23 fsckv2 systemd[1]: Failed to start BIND Domain Name Server.
For testing, I also `apt-get -b source`d bind9 from testing/unstable (9.17.21-1) but it exhibits the
same non-working bevaviour.
(If needed I can provide all config in private mail, but am loathe to disclose them publicly as it's quite
extensive (this is a nameserver for quite some domains, plus the resolver for all my internal networks).)
Kind regards and grateful for any hints,
Robert
-- System Information:
Debian Release: 11.2
APT prefers stable
APT policy: (990, 'stable'), (500, 'stable-updates'), (500, 'stable-security'), (500, 'testing'), (500, 'oldstable')
Architecture: amd64 (x86_64)
Foreign Architectures: i386
Kernel: Linux 5.10.0-10-amd64 (SMP w/16 CPU threads)
Kernel taint flags: TAINT_PROPRIETARY_MODULE, TAINT_OOT_MODULE, TAINT_UNSIGNED_MODULE
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8), LANGUAGE not set
Shell: /bin/sh linked to /usr/bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled
Versions of packages bind9 depends on:
ii adduser 3.118
ii bind9-libs 1:9.16.22-1~deb11u1
ii bind9-utils 1:9.16.22-1~deb11u1
ii debconf [debconf-2.0] 1.5.77
ii dns-root-data 2021011101
ii init-system-helpers 1.60
ii iproute2 5.10.0-4
ii libc6 2.31-13+deb11u2
ii libcap2 1:2.44-1
ii libfstrm0 0.6.0-1+b1
ii libjson-c5 0.15-2
ii liblmdb0 0.9.24-1
ii libmaxminddb0 1.5.2-1
ii libprotobuf-c1 1.3.3-1+b2
ii libssl1.1 1.1.1k-1+deb11u1
ii libuv1 1.40.0-2
ii libxml2 2.9.10+dfsg-6.7
ii lsb-base 11.1.0
ii netbase 6.3
ii zlib1g 1:1.2.11.dfsg-2
bind9 recommends no packages.
Versions of packages bind9 suggests:
pn bind-doc <none>
pn dnsutils <none>
pn resolvconf <none>
pn ufw <none>
-- Configuration Files:
/etc/bind/named.conf changed [not included]
/etc/bind/named.conf.local changed [not included]
/etc/bind/named.conf.options changed [not included]
-- debconf information:
bind9/run-resolvconf: false
bind9/start-as-user: bind
bind9/different-configuration-file:
Ondřej Surý
--
Ondřej Surý <ond...@sury.org> (He/Him)
> On 26. 12. 2021, at 12:18, Robert Waldner <waldn...@waldner.priv.at> wrote:
>
> Package: bind9
Simon Deziel
Since you are hitting permission issues, I'd also check dmesg for
AppArmor denial messages (`dmesg | grep apparmor`).
Simon
Robert Waldner
On Sun, 26 Dec 2021 10:47:42 -0500, Simon Deziel writes:
>What's in /etc/default/named? Chroot'ing could cause some issues.
-------
#
# run resolvconf?
RESOLVCONF=no
# startup options for the server
OPTIONS="-u bind"
-------
>Since you are hitting permission issues, I'd also check dmesg for
>AppArmor denial messages (`dmesg | grep apparmor`).
root@fsckv2:~# dmesg | grep apparmor
[ 6.889374] audit: type=1400 audit(1640488235.484:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="libreoffice-senddoc" pid=900 comm="apparmor_parser"
[ 6.889470] audit: type=1400 audit(1640488235.484:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name="libreoffice-xpdfimport" pid=901 comm="apparmor_parser"
[ 6.889533] audit: type=1400 audit(1640488235.484:4): apparmor="STATUS" operation="profile_load" profile="unconfined" name="lsb_release" pid=889 comm="apparmor_parser"
[ 6.889746] audit: type=1400 audit(1640488235.484:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name="libreoffice-oopslash" pid=896 comm="apparmor_parser"
[ 6.889794] audit: type=1400 audit(1640488235.484:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="nvidia_modprobe" pid=894 comm="apparmor_parser"
[ 6.889797] audit: type=1400 audit(1640488235.484:7): apparmor="STATUS" operation="profile_load" profile="unconfined" name="nvidia_modprobe//kmod" pid=894 comm="apparmor_parser"
[ 6.890474] audit: type=1400 audit(1640488235.484:8): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/bin/man" pid=891 comm="apparmor_parser"
[ 6.890477] audit: type=1400 audit(1640488235.484:9): apparmor="STATUS" operation="profile_load" profile="unconfined" name="man_filter" pid=891 comm="apparmor_parser"
[ 6.890479] audit: type=1400 audit(1640488235.484:10): apparmor="STATUS" operation="profile_load" profile="unconfined" name="man_groff" pid=891 comm="apparmor_parser"
[ 6.891157] audit: type=1400 audit(1640488235.484:11): apparmor="STATUS" operation="profile_load" profile="unconfined" name="named" pid=899 comm="apparmor_parser"
Kind regards,
Robert
--
-- Acronyms explained: TCPA
-- (T)otal (C)ontrol of (P)rivate (A)ssets
-- - captainiglo
Robert Waldner
On Sun, 26 Dec 2021 14:20:21 +0100, =?utf-8?Q?Ond=C5=99ej_Sur=C3=BD?= writes:
>Well, what is your working directory and is it writeable by user:group
> under which named runs at your system?
directory "/etc/bind";
root@fsckv2:~# ls -la /etc/bind/
total 104
drwxrwsr-x 3 root bind 4096 Dec 26 11:35 .
root@fsckv2:~# grep OPTIONS /etc/default/named
OPTIONS="-u bind"
Running named from buster, 1:9.11.5.P4+dfsg-5.1, started normally from
systemd:
root@fsckv2:~# ps auxwww| grep [n]amed
bind 133379 0.0 0.9 1728372 323376 ? Ssl 12:09 0:04 /usr/sbin/named -f -u bind
Kind regards,
Robert