Bug 18140

Summary: named does not start from systemd: ENGINE_by_id failed (crypto failure)
Product: Mageia Reporter: Martin Ward <martin>
Component: RPM PackagesAssignee: Guillaume Rousse <guillomovitch>
Status: RESOLVED INVALID QA Contact:
Severity: major    
Priority: High CC: marja11
Version: 5Keywords: NEEDINFO
Target Milestone: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Source RPM: bind CVE:
Status comment:

Description Martin Ward 2016-04-06 13:25:05 CEST
Description of problem:

When I try to run named from System Services in the Control Centre it does not start. Running from the command line with:

systemctl start named

gives the error:

Job for named.service failed. See "systemctl status named.service" and "journalctl -xe" for details.


"systemctl status named.service -l" gives:

* named.service - Berkeley Internet Name Domain (DNS)
   Loaded: loaded (/usr/lib/systemd/system/named.service; enabled)
   Active: failed (Result: exit-code) since Wed 2016-04-06 12:23:32 BST; 27s ago
  Process: 28252 ExecStart=/usr/sbin/named -u named -t /var/lib/named $OPTIONS (code=exited, status=1/FAILURE)
  Process: 28248 ExecStartPre=/usr/sbin/named-checkconf -t /var/lib/named -z /etc/named.conf (code=exited, status=0/SUCCESS)
  Process: 28225 ExecStartPre=/usr/sbin/setup-named-chroot.sh /var/lib/named on (code=exited, status=0/SUCCESS)

Apr 06 12:23:32 pingu6 named-checkconf[28248]: zone 0.in-addr.arpa/IN: loaded serial 0
Apr 06 12:23:32 pingu6 named[28253]: ENGINE_by_id failed (crypto failure)
Apr 06 12:23:32 pingu6 named[28253]: error:25070067:DSO support routines:DSO_load:could not load the shared library:dso_lib.c:233:
Apr 06 12:23:32 pingu6 named[28253]: error:260B6084:engine routines:DYNAMIC_LOAD:dso not found:eng_dyn.c:467:
Apr 06 12:23:32 pingu6 named[28253]: error:2606A074:engine routines:ENGINE_by_id:no such engine:eng_list.c:390:id=gost
Apr 06 12:23:32 pingu6 named[28253]: initializing DST: crypto failure
Apr 06 12:23:32 pingu6 systemd[1]: named.service: control process exited, code=exited status=1
Apr 06 12:23:32 pingu6 systemd[1]: Failed to start Berkeley Internet Name Domain (DNS).
Apr 06 12:23:32 pingu6 systemd[1]: Unit named.service entered failed state.
Apr 06 12:23:32 pingu6 systemd[1]: named.service failed.


Version-Release number of selected component (if applicable):

bind-9.10.3.P4-1.mga5


How reproducible:

Steps to Reproduce:
1. Run: systemctl start named
2. See the error:

Job for named.service failed. See "systemctl status named.service" and "journalctl -xe" for details.
Martin Ward 2016-04-18 21:38:25 CEST

Priority: Normal => High

Comment 1 Marja Van Waes 2016-04-24 16:29:10 CEST
@ Colin 

I didn't want to assign this bug to you without understanding more of it, since you're so very busy. However, you probably need less than a minute to understand whether it should be reassigned or not, so now assigning to you anyway :-p

CC: (none) => marja11
Assignee: bugsquad => mageia

Comment 2 Colin Guthrie 2016-04-25 10:30:33 CEST
It's certainly not a systemd issue. It's showing error output from the named command so looks like a simple named configuration problem.
Comment 3 Marja Van Waes 2016-04-25 10:56:58 CEST
(In reply to Colin Guthrie from comment #2)
> It's certainly not a systemd issue. It's showing error output from the named
> command so looks like a simple named configuration problem.

Thanks, Colin :-)

Reassigning to guillomovitch, then. He'll know which information to ask from the user to confirm the problem is with the configuration.

Assignee: mageia => guillomovitch
Source RPM: named => bind

Comment 4 Guillaume Rousse 2016-07-06 20:23:23 CEST
I can't reproduce here.

Check you have:
- the openssl-engines package installed: lib(64)?openssl-engines1.0.0
- the named chroot correctly setup: you should have /usr/lib(64)?/openssl bind-mounted on /var/lib/named/usr/lib(64)?/openssl
- any exotic crypto configuration (DNSSEC, for instance)
Comment 5 Martin Ward 2016-07-06 22:59:42 CEST
> Check you have:
> - the openssl-engines package installed: lib(64)?openssl-engines1.0.0

% rpm -qa | grep openssl-engine
libopenssl-engines1.0.0-1.0.2h-1.mga5
lib64openssl-engines1.0.0-1.0.2h-1.mga5

> - the named chroot correctly setup: you should have /usr/lib(64)?/openssl
> bind-mounted on /var/lib/named/usr/lib(64)?/openssl

Directory /var/lib/named/usr/lib64/openssl/1.0.1p/engines
exists and contains various shared object libraries.

mount output ends with:

/dev/sda5 on /var/lib/named/etc/named type ext4 (ro,relatime,data=ordered)
/dev/sda5 on /etc/named type ext4 (rw,relatime,data=ordered)
/dev/sda5 on /var/lib/named/usr/lib64/bind type ext4 (ro,relatime,data=ordered)
/dev/sda5 on /usr/lib64/bind type ext4 (rw,relatime,data=ordered)

/dev/sda5 is my root partition.
All the above directories (/var/lib/named/etc/named etc.) are empty.

> - any exotic crypto configuration (DNSSEC, for instance)

I don't think so.

The problem occurs on two Mageia installations on very similar machines
which were originally installed with Mageia 3, then upgraded to 4 and then 5.

I have another Mageia 5 installation on a virtualbox for which named works.
(This was installed from scratch). This has four extra mounts listed
at the end of the output of "mount":

/dev/sda1 on /var/lib/named/etc/named.conf type ext4 (ro,relatime,data=ordered)
/dev/sda1 on /var/lib/named/etc/rndc.key type ext4 (ro,relatime,data=ordered)
/dev/sda1 on /var/lib/named/etc/named.iscdlv.key type ext4 (ro,relatime,data=ordered)
/dev/sda1 on /var/lib/named/etc/named.root.key type ext4 (ro,relatime,data=ordered)
/dev/sda1 on /var/lib/named/etc/named type ext4 (ro,relatime,data=ordered)
/dev/sda1 on /var/lib/named/usr/lib64/bind type ext4 (ro,relatime,data=ordered)
/dev/sda1 on /var/lib/named/usr/lib64/openssl type ext4 (ro,relatime,data=ordered)
/dev/sda1 on /var/lib/named/var/named type ext4 (rw,relatime,data=ordered)
Comment 6 Guillaume Rousse 2016-08-21 14:29:03 CEST
You seem to have suspicious mount points in mount output:
/dev/sda5 on /var/lib/named/etc/named type ext4 (ro,relatime,data=ordered)
-> this one is normal, it is /etc/named bind mounted in bind chroot
/dev/sda5 on /etc/named type ext4 (rw,relatime,data=ordered)
-> this one is not normal
/dev/sda5 on /var/lib/named/usr/lib64/bind type ext4 (ro,relatime,data=ordered)
-> this one is normal, it is usr/lib64/bind mounted in bind chroot
/dev/sda5 on /usr/lib64/bind type ext4 (rw,relatime,data=ordered)
-> this one is not normal

The chroot setup is done with /usr/sbin/setup-named-chroot.sh script, which is supposed to be automatically called by named.service when starting or stopping the service. I suspect something else incorrectly called '/usr/sbin/setup-named-chroot.sh / on', actually creating another chroot on original file locations...

Can you try the following sequence, and check if it changes anything ?
$> systemcl stop named.service
$> /usr/sbin/setup-named-chroot.sh / off
$> systemcl start named.service
Comment 7 Martin Ward 2016-08-23 22:48:03 CEST
Before running:

# mount | grep sda5
/dev/sda5 on / type ext4 (rw,relatime,data=ordered)
/dev/sda5 on /var/lib/named/etc/named type ext4 (ro,relatime,data=ordered)
/dev/sda5 on /var/lib/named/usr/lib64/bind type ext4 (ro,relatime,data=ordered)

# systemctl stop named.service 
# mount | grep sda5
/dev/sda5 on / type ext4 (rw,relatime,data=ordered)
/dev/sda5 on /var/lib/named/etc/named type ext4 (ro,relatime,data=ordered)
/dev/sda5 on /var/lib/named/usr/lib64/bind type ext4 (ro,relatime,data=ordered)

# /usr/sbin/setup-named-chroot.sh / off
# mount | grep sda5
/dev/sda5 on / type ext4 (rw,relatime,data=ordered)
/dev/sda5 on /var/lib/named/etc/named type ext4 (ro,relatime,data=ordered)
/dev/sda5 on /var/lib/named/usr/lib64/bind type ext4 (ro,relatime,data=ordered)

# systemctl start named.service (y|n|e|a)? yes
Job for named.service failed. See "systemctl status named.service" and "journalctl -xe" for details.

# mount | grep sda5
/dev/sda5 on / type ext4 (rw,relatime,data=ordered)
/dev/sda5 on /var/lib/named/etc/named type ext4 (ro,relatime,data=ordered)
/dev/sda5 on /var/lib/named/usr/lib64/bind type ext4 (ro,relatime,data=ordered)
/dev/sda5 on /var/lib/named/etc/named type ext4 (ro,relatime,data=ordered)
/dev/sda5 on /etc/named type ext4 (rw,relatime,data=ordered)
/dev/sda5 on /var/lib/named/usr/lib64/bind type ext4 (ro,relatime,data=ordered)
/dev/sda5 on /usr/lib64/bind type ext4 (rw,relatime,data=ordered)

# journalctl -xe
Aug 23 21:43:37 pingu6 named-checkconf[31841]: zone localhost.localdomain/IN: loaded serial 0
Aug 23 21:43:37 pingu6 named-checkconf[31841]: zone localhost/IN: loaded serial 0
Aug 23 21:43:37 pingu6 named-checkconf[31841]: zone 1.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.ip6.arpa/IN: loaded serial 0
Aug 23 21:43:37 pingu6 named-checkconf[31841]: zone 1.0.0.127.in-addr.arpa/IN: loaded serial 0
Aug 23 21:43:37 pingu6 named-checkconf[31841]: zone 0.in-addr.arpa/IN: loaded serial 0
Aug 23 21:43:37 pingu6 named[31847]: starting BIND 9.10.3-P4 <id:ebd72b3> -u named -t /var/lib/named
Aug 23 21:43:37 pingu6 named[31847]: built with '--build=x86_64-mageia-linux-gnu' '--prefix=/usr' '--exec-prefix=/usr' '--bindir=/usr/bin' '--sbindir=/usr/sb
Aug 23 21:43:37 pingu6 named[31847]: ----------------------------------------------------
Aug 23 21:43:37 pingu6 named[31847]: BIND 9 is maintained by Internet Systems Consortium,
Aug 23 21:43:37 pingu6 named[31847]: Inc. (ISC), a non-profit 501(c)(3) public-benefit
Aug 23 21:43:37 pingu6 named[31847]: corporation.  Support and training for BIND 9 are
Aug 23 21:43:37 pingu6 named[31847]: available at https://www.isc.org/support
Aug 23 21:43:37 pingu6 named[31847]: ----------------------------------------------------
Aug 23 21:43:37 pingu6 named[31847]: adjusted limit on open files from 4096 to 1048576
Aug 23 21:43:37 pingu6 named[31847]: found 8 CPUs, using 8 worker threads
Aug 23 21:43:37 pingu6 named[31847]: using 4 UDP listeners per interface
Aug 23 21:43:37 pingu6 named[31847]: using up to 4096 sockets
Aug 23 21:43:37 pingu6 named[31847]: ENGINE_by_id failed (crypto failure)
Aug 23 21:43:37 pingu6 named[31847]: error:25070067:DSO support routines:DSO_load:could not load the shared library:dso_lib.c:233:
Aug 23 21:43:37 pingu6 named[31847]: error:260B6084:engine routines:DYNAMIC_LOAD:dso not found:eng_dyn.c:467:
Aug 23 21:43:37 pingu6 named[31847]: error:2606A074:engine routines:ENGINE_by_id:no such engine:eng_list.c:390:id=gost
Aug 23 21:43:37 pingu6 named[31847]: initializing DST: crypto failure
Aug 23 21:43:37 pingu6 named[31847]: exiting (due to fatal error)
Aug 23 21:43:37 pingu6 systemd[1]: named.service: control process exited, code=exited status=1
Aug 23 21:43:37 pingu6 systemd[1]: Failed to start Berkeley Internet Name Domain (DNS).
-- Subject: Unit named.service has failed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit named.service has failed.
-- 
-- The result is failed.
Aug 23 21:43:37 pingu6 systemd[1]: Unit named.service entered failed state.
Aug 23 21:43:37 pingu6 systemd[1]: named.service failed.
Comment 8 Guillaume Rousse 2017-05-26 12:50:11 CEST
I suspect a duplicate of bug #12425.
Comment 9 Guillaume Rousse 2017-05-26 12:50:59 CEST
Can you check latest release also fix this issue ?

Keywords: (none) => NEEDINFO
Status: NEW => ASSIGNED

Comment 10 Martin Ward 2017-05-26 14:09:53 CEST
The current version of bind that I have is: bind-9.10.3.P4-1.2.mga5

With this I initially had a different error:

# systemctl start named

Job for named.service failed. See "systemctl status named.service" and "journalctl -xe" for details.

# systemctl -l status named.service

* named.service - Berkeley Internet Name Domain (DNS)
   Loaded: loaded (/usr/lib/systemd/system/named.service; enabled)
   Active: failed (Result: exit-code) since Fri 2017-05-26 12:47:03 BST; 24s ago
  Process: 4942 ExecStartPre=/usr/sbin/named-checkconf -t /var/lib/named -z /etc/named.conf (code=exited, status=1/FAILURE)
  Process: 4919 ExecStartPre=/usr/sbin/setup-named-chroot.sh /var/lib/named on (code=exited, status=0/SUCCESS)

May 26 12:47:03 pingu6 named-checkconf[4942]: zone 1.0.0.127.in-addr.arpa/IN: loading from master file named.loopback failed: file not found
May 26 12:47:03 pingu6 named-checkconf[4942]: zone 1.0.0.127.in-addr.arpa/IN: not loaded due to errors.
May 26 12:47:03 pingu6 named-checkconf[4942]: _default/1.0.0.127.in-addr.arpa/IN: file not found
May 26 12:47:03 pingu6 named-checkconf[4942]: zone 0.in-addr.arpa/IN: loading from master file named.empty failed: file not found
May 26 12:47:03 pingu6 named-checkconf[4942]: zone 0.in-addr.arpa/IN: not loaded due to errors.
May 26 12:47:03 pingu6 named-checkconf[4942]: _default/0.in-addr.arpa/IN: file not found
May 26 12:47:03 pingu6 systemd[1]: named.service: control process exited, code=exited status=1
May 26 12:47:03 pingu6 systemd[1]: Failed to start Berkeley Internet Name Domain (DNS).
May 26 12:47:03 pingu6 systemd[1]: Unit named.service entered failed state.
May 26 12:47:03 pingu6 systemd[1]: named.service failed.


Directory /var/named contained the files it was looking for (named.loopback etc) so I copied
/var/named/named.* to /var/lib/named/var/named/.

Trying again gave another error:

May 26 12:51:25 pingu6 named[5383]: found 8 CPUs, using 8 worker threads
May 26 12:51:25 pingu6 named[5383]: using 4 UDP listeners per interface
May 26 12:51:25 pingu6 named[5383]: using up to 4096 sockets
May 26 12:51:25 pingu6 named[5383]: ENGINE_by_id failed (crypto failure)
May 26 12:51:25 pingu6 named[5383]: error:25070067:DSO support routines:DSO_load:could not load the shared library:dso_lib.c:233:
May 26 12:51:25 pingu6 named[5383]: error:260B6084:engine routines:DYNAMIC_LOAD:dso not found:eng_dyn.c:467:
May 26 12:51:25 pingu6 systemd[1]: named.service: control process exited, code=exited status=1
May 26 12:51:25 pingu6 systemd[1]: Failed to start Berkeley Internet Name Domain (DNS).
May 26 12:51:25 pingu6 systemd[1]: Unit named.service entered failed state.
May 26 12:51:25 pingu6 systemd[1]: named.service failed.

My working installation has some .so libraries in  /var/lib/named/usr/lib64/openssl/1.0.2k
while this installation has directory /var/lib/named/usr/lib64/openssl/1.0.1p

The installed version of openssl-engines is lib64openssl-engines1.0.0-1.0.2k-1.mga5
which contains the directory /usr/lib64/openssl/1.0.2k

So I copied the directory  /usr/lib64/openssl/1.0.2k to /var/lib/named/usr/lib64/openssl/
and now named appears to be working!
Comment 11 Guillaume Rousse 2017-05-26 15:21:34 CEST
Both issues seems to comes from a non-populated chroot, despite setup-named-chroot.sh script seems to be run successfully at service start:
- /var/named should be bind-mounted at /var/lib/named/var/named
- /usr/lib64/openssl should be bind-mounted at /var/lib/named/usr/lib64/openssl

There is a safety check in the chroot creation script, tough: if the target directories are not empty, mounting doesn't occur:
# skip if target is not empty.
[ `ls -1A $target | wc -l` -ne 0 ] && continue

As you seem to workaround those issues by manually copying missing files, you may be actually part of the problem here. Indeed, this does not explain how did this occur initially. Can you check with a clean situation, ie removing all files from both target directories in the chroot, while named is not running ?
Comment 12 Martin Ward 2017-05-26 15:31:17 CEST
It works with the directories emptied as suggested, thanks.
Comment 13 Guillaume Rousse 2017-07-18 17:37:18 CEST
Closing, as there is no evidence of a software or packaging defect here.

Status: ASSIGNED => RESOLVED
Resolution: (none) => INVALID