While trying to deploy freeIPA on an up-to-date CentOS-7 AND f-28, I always hit the following error: [36/44]: initializing group membership [error] NotFound: no such entry ipa.ipapython.install.cli.install_tool(CompatServerMasterInstall): ERROR no such entry ipa.ipapython.install.cli.install_tool(CompatServerMasterInstall): ERROR The ipa-server-install command failed. See /var/log/ipaserver-install.log for more information
This prevent the service to be deployed, and I can't do anything against that.
It fails while initializing group membership
Installation should succeed
package freeipa-server is not installed package freeipa-client is not installed ipa-server-4.5.4-10.el7.centos.4.4.x86_64 ipa-client-4.5.4-10.el7.centos.4.4.x86_64 389-ds-base-1.3.7.5-28.el7_5.x86_64 pki-ca-10.5.1-15.el7_5.noarch krb5-server-1.15.1-19.el7.x86_64
I'm trying to deploy that on a virtual machine with 4G of RAM, and about 40G of free space. It has one network interface, with multiple IP attached (2 ipv4, 1 ipv6).
You should get the complete ipaserver-install.log attached to this issue.
Thank you for your help! <img alt="ipaserver-install.log" src="/freeipa/issue/raw/files/030caf7fb794f978924752a929e17df283421899ddf2adb917662457c8b43318-ipaserver-install.log" />
I also add the logs of dirsrv service, as I suspect the issue is located in there, especially seeing the following lines: [26/Nov/2018:17:26:42.395882240 +0100] - ERR - cos-plugin - cos_dn_defs_cb - Skipping CoS Definition cn=Password Policy,cn=accounts,dc=ipa,dc=internux,dc=ch--no CoS Templates found, which should be added before the CoS Definition.
<img alt="access" src="/freeipa/issue/raw/files/3993c5e7bc22d18ea0b554f9ea936c34bc01061b52e3d565964d74e3d4cdf7f7-access" /><img alt="audit" src="/freeipa/issue/raw/files/e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855-audit" /><img alt="errors" src="/freeipa/issue/raw/files/33b4270f49c6078386cb84f72f15e73c8049548803d1076e67d86198e710d805-errors" />
Which version did you try to install on F28? ipa-server-4.5.4-10.el7.centos.4.4.x86_64 is a CentOS version.
ipa-server-4.5.4-10.el7.centos.4.4.x86_64
@internux the way I understand "an up-to-date CentOS-7 AND f-28" and "get some up-to-date Fedora-28 or CentOS-7 server" is that you get the same error with either Fedora 28 or CentOS 7.5 up-to-date as of today and that you are not mixing packages. Is that right?
So, regarding fedora version: base package is freeipa-server-4.7.0-3.fc28.x86_64.
When I say "up-to-date CentOS-7 and f-28", I mean: either an instance with centos-7 and a yum update -y done, OR an instance with f-28 server and a dnf update -y done.
yum update -y
dnf update -y
I don't mix up packages nor repositories.
I'm adding the log of the fedora deploy.
In both cases, the command I issued was: ipa-server-install -r IPA.INTERNUX.CH -n ipa.internux.ch -N
ipa-server-install -r IPA.INTERNUX.CH -n ipa.internux.ch -N
<img alt="ipaserver-install.log" src="/freeipa/issue/raw/files/4ae64bec90c80b15539fcbb440f8f0f75e1ffd77757c4bc22d3731e2fa5173de-ipaserver-install.log" /> <img alt="access" src="/freeipa/issue/raw/files/8a0ce8fe14a96ad0d5082caf37e150dcc853a1ad82ed2b7ade056d7994c540f5-access" /><img alt="audit" src="/freeipa/issue/raw/files/e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855-audit" /><img alt="errors" src="/freeipa/issue/raw/files/1cc36bdff33f681145e52d35139532ead3235ed2bdc0d10ec6ddff8ebeb5b3b7-errors" />
I just installed a server on F28 successfully with packages:
freeipa-server-4.7.0-3.fc28.x86_64 freeipa-client-4.7.0-3.fc28.x86_64 package ipa-server is not installed package ipa-client is not installed 389-ds-base-1.4.0.16-1.fc28.x86_64 pki-ca-10.6.6-1.fc28.noarch krb5-server-1.16.1-21.fc28.x86_64
In your case installation fails in wait_for_task for task cn=IPA install 1543252698, cn=memberof task, cn=tasks, cn=config. I see that the task gets created but it no longer available in the wait step. The 389-DS clearly show that the task is running [26/Nov/2018:18:18:31.314115922 +0100] - INFO - memberof-plugin - memberof_fixup_task_thread - Memberof task starts (filter: "(objectclass=*)") ....
wait_for_task
cn=IPA install 1543252698, cn=memberof task, cn=tasks, cn=config
[26/Nov/2018:18:18:31.314115922 +0100] - INFO - memberof-plugin - memberof_fixup_task_thread - Memberof task starts (filter: "(objectclass=*)") ...
The problem could be related to the fact that there is a pretty long delay between the waiting call and the next step. It's 130 seconds but the task only has a TTL of 10 seconds.
2018-11-26T17:18:31Z DEBUG Waiting for memberof task to complete. 2018-11-26T17:20:41Z DEBUG Traceback (most recent call last):
I see the same long delay in the other log file:
2018-11-26T16:26:43Z DEBUG Waiting for memberof task to complete. 2018-11-26T16:28:50Z DEBUG Traceback (most recent call last):
What are the hardware specs of your machine?
It's a virtual machine hosted in Hetzner cloud, a cx21, with the following specs: - 2vCPU - 4GB RAM - 40GB disk space
So it might be some kind of timeout somewhere? Would that be tunable?
In order to check if the number of CPU can impact that, I just tested with another instance type, a cx41, with the following specs: - 4vCPU - 16G RAM - 160G disk space
Same issue at the same location :(. The vCPU are Intel Xeon Processor (Skylake, IBRS) 2099.986 MHz, so they aren't that slow...
I didn't find requirements for a freeIPA deploy... ?
The CPU might not be the culprit there.
Can you check how much I/O and I/O wait there is at install time? You can do so with iostat, sar or even top for starters. I've just done an install and I/O wait as reported by sar never went above 8% for me.
Hm, just checked - iostat doesn't show %iowait above 2 during the deploy..... Guess the instance is pretty fast, at least it should deploy on that kind of hardware without trouble :/.
The acccess logs are incomplete. There are no SRCH entries for the installation task. Could you please post the full access log? There should be at least one entry that looks like SRCH base="cn=IPA install 1543254023,cn=memberof task,cn=tasks,cn=config" scope=0 filter="(objectClass=*)" attrs="nstasklog nstaskexitcode nstasktotalitems nstaskstatus nstaskcurrentitem".
acccess
SRCH base="cn=IPA install 1543254023,cn=memberof task,cn=tasks,cn=config" scope=0 filter="(objectClass=*)" attrs="nstasklog nstaskexitcode nstasktotalitems nstaskstatus nstaskcurrentitem"
IIRC 389-DS doesn't flush the access log for every log line. Instead it batches disk flushes for performance reasons. You either have to wait half a minute to a minute or shut down the LDAP server.
Here are the logs after a shutdown of the ns-slapd.service, and a sync. It comes from a cx21 instance with f-28.
ns-slapd.service
sync
I can also provide some access to a dropable instance if more tests are needed.
<img alt="access" src="/freeipa/issue/raw/files/e49bd64c94d7adabea0ce9415738a2e717d7456b607b4fb670ab16b61d63237d-access" /><img alt="audit" src="/freeipa/issue/raw/files/e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855-audit" /><img alt="errors" src="/freeipa/issue/raw/files/d7697c5eee7c59ba539eb8bad1c49ec7a2cbc8c40667a639e89e72fe7af549b2-errors" />
There is a huge gap between the ADD entry and the network connection for SRCH entry. On a typical system the time difference should be more like 0.2 seconds, not more than 2 minutes.
[27/Nov/2018:12:02:56.619233663 +0100] conn=14 fd=65 slot=65 connection from local to /var/run/slapd-IPA-INTERNUX-CH.socket [27/Nov/2018:12:02:56.619553267 +0100] conn=14 AUTOBIND dn="cn=Directory Manager" [27/Nov/2018:12:02:56.619559209 +0100] conn=14 op=0 BIND dn="cn=Directory Manager" method=sasl version=3 mech=EXTERNAL [27/Nov/2018:12:02:56.619637939 +0100] conn=14 op=0 RESULT err=0 tag=97 nentries=0 etime=0.0000338188 dn="cn=Directory Manager" [27/Nov/2018:12:02:56.619828872 +0100] conn=14 op=1 ADD dn="cn=IPA install 1543316559,cn=memberof task,cn=tasks,cn=config" [27/Nov/2018:12:02:56.629259886 +0100] conn=14 op=2 UNBIND [27/Nov/2018:12:02:56.629295319 +0100] conn=14 op=2 fd=65 closed - U1 [27/Nov/2018:12:02:56.629320061 +0100] conn=14 op=1 RESULT err=0 tag=105 nentries=0 etime=0.0009593956 [27/Nov/2018:12:05:05.906480043 +0100] conn=15 fd=65 slot=65 connection from 195.201.47.87 to 195.201.47.87 [27/Nov/2018:12:05:05.907147421 +0100] conn=15 op=0 BIND dn="cn=directory manager" method=128 version=3 [27/Nov/2018:12:05:06.028316793 +0100] conn=15 op=0 RESULT err=0 tag=97 nentries=0 etime=0.0121547465 dn="cn=directory manager" [27/Nov/2018:12:05:06.033143953 +0100] conn=15 op=1 SRCH base="cn=IPA install 1543316559,cn=memberof task,cn=tasks,cn=config" scope=0 filter="(objectClass=*)" attrs="nstaskexitcode nstasktotalitems nstasklog nstaskstatus nstaskcurrentitem" [27/Nov/2018:12:05:06.033635650 +0100] conn=15 op=1 RESULT err=32 tag=101 nentries=0 etime=0.0001194399 [27/Nov/2018:12:05:06.146949810 +0100] conn=15 op=2 UNBIND [27/Nov/2018:12:05:06.147026037 +0100] conn=15 op=2 fd=65 closed - U1 [27/Nov/2018:12:05:06.338302522 +0100] conn=3 op=9 UNBIND [27/Nov/2018:12:05:06.338331408 +0100] conn=3 op=9 fd=64 closed - U1
What's the time stamp of the log line Waiting for memberof task to complete in the ipaserver install log? If it's close to 12:02:56, then the problem might be caused by a networking problem. The init_memberof call is the first time a TCP connection is used. Before the call, all connections use a Unix socket.
Waiting for memberof task to complete
12:02:56
init_memberof
How are your Python and pdb skills? Could you step through init_memberof method in /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py with pdb (import pdb; pdb.set_trace)?
/usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py
import pdb; pdb.set_trace
I don't know about pdb, just saw it once running in a tmate. So it will be hard I guess. But I can at least push the set_trace thingy. Just let me trash the instance and rebuild it, it's better on clean system.
Err, it's import pdb; pdb.set_trace(). Please also increase the debug level of python-ldap:
import pdb; pdb.set_trace()
def init_memberof(self): # NEW CODE STARTS HERE import ldap, pdb ldap.set_option(ldap.OPT_DEBUG_LEVEL, 255) pdb.set_trace() if not self.run_init_memberof: return self._ldap_mod("memberof-task.ldif", self.sub_dict)
At some point during the installation, you'll reach an interactive prompt. Just enter n to execute the next line. One of the lines should take 2 minutes to execute, probably ipaldap.LDAPClient(ldap_uri). The extended debug level should help you to understand what is taking so long.
n
ipaldap.LDAPClient(ldap_uri)
hmmm, so, I think I did it right, at least I got the prompt where it was intended, and could go with the set_trace(). Here's the output I got in the shell.
The task that took a long time was the simple_bind.
[37/44]: initializing group membership > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(698)init_memberof() -> if not self.run_init_memberof: (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(701)init_memberof() -> self._ldap_mod("memberof-task.ldif", self.sub_dict) (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(703)init_memberof() -> dn = DN(('cn', 'IPA install %s' % self.sub_dict["TIME"]), ('cn', 'memberof task'), (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(704)init_memberof() -> ('cn', 'tasks'), ('cn', 'config')) (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(705)init_memberof() -> logger.debug("Waiting for memberof task to complete.") (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(706)init_memberof() -> ldap_uri = ipaldap.get_ldap_uri(self.fqdn) (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(707)init_memberof() -> conn = ipaldap.LDAPClient(ldap_uri) (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(708)init_memberof() -> if self.dm_password: (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(709)init_memberof() -> conn.simple_bind(bind_dn=ipaldap.DIRMAN_DN, (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(710)init_memberof() -> bind_password=self.dm_password) (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(713)init_memberof() -> replication.wait_for_task(conn, dn) (Pdb) ipalib.errors.NotFound: no such entry > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(713)init_memberof() -> replication.wait_for_task(conn, dn) (Pdb) n --Return-- > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(713)init_memberof()->None -> replication.wait_for_task(conn, dn) (Pdb) n ipalib.errors.NotFound: no such entry > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(591)run_step() -> method() (Pdb) n --Return-- > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(591)run_step()->None -> method() (Pdb) n ipalib.errors.NotFound: no such entry > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(605)start_creation() -> run_step(full_msg, method) (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(607)start_creation() -> except BaseException as e: [37/44]: initializing group membership > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(698)init_memberof() -> if not self.run_init_memberof: (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(701)init_memberof() -> self._ldap_mod("memberof-task.ldif", self.sub_dict) (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(703)init_memberof() -> dn = DN(('cn', 'IPA install %s' % self.sub_dict["TIME"]), ('cn', 'memberof task'), (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(704)init_memberof() -> ('cn', 'tasks'), ('cn', 'config')) (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(705)init_memberof() -> logger.debug("Waiting for memberof task to complete.") (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(706)init_memberof() -> ldap_uri = ipaldap.get_ldap_uri(self.fqdn) (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(707)init_memberof() -> conn = ipaldap.LDAPClient(ldap_uri) (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(708)init_memberof() -> if self.dm_password: (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(709)init_memberof() -> conn.simple_bind(bind_dn=ipaldap.DIRMAN_DN, (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(710)init_memberof() -> bind_password=self.dm_password) (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(713)init_memberof() -> replication.wait_for_task(conn, dn) (Pdb) ipalib.errors.NotFound: no such entry > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(713)init_memberof() -> replication.wait_for_task(conn, dn) (Pdb) n --Return-- > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(713)init_memberof()->None -> replication.wait_for_task(conn, dn) (Pdb) n ipalib.errors.NotFound: no such entry > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(591)run_step() -> method() (Pdb) n --Return-- > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(591)run_step()->None -> method() (Pdb) n ipalib.errors.NotFound: no such entry > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(605)start_creation() -> run_step(full_msg, method) (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(607)start_creation() -> except BaseException as e: (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(608)start_creation() -> if not (isinstance(e, SystemExit) and (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(611)start_creation() -> logger.debug("%s", traceback.format_exc()) (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(612)start_creation() -> self.print_msg(' [error] %s: %s' % (type(e).__name__, e)) (Pdb) n [error] NotFound: no such entry > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(615)start_creation() -> for message, method, run_after_failure in steps_iter: (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(616)start_creation() -> if run_after_failure: (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(615)start_creation() -> for message, method, run_after_failure in steps_iter: (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(616)start_creation() -> if run_after_failure: (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(615)start_creation() -> for message, method, run_after_failure in steps_iter: (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(616)start_creation() -> if run_after_failure: (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(615)start_creation() -> for message, method, run_after_failure in steps_iter: (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(616)start_creation() -> if run_after_failure: (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(615)start_creation() -> for message, method, run_after_failure in steps_iter: (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(616)start_creation() -> if run_after_failure: (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(615)start_creation() -> for message, method, run_after_failure in steps_iter: (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(616)start_creation() -> if run_after_failure: (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(615)start_creation() -> for message, method, run_after_failure in steps_iter: (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(616)start_creation() -> if run_after_failure: (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(615)start_creation() -> for message, method, run_after_failure in steps_iter: (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(619)start_creation() -> raise (Pdb) n --Return-- > /usr/lib/python3.6/site-packages/ipaserver/install/service.py(619)start_creation()->None -> raise (Pdb) n ipalib.errors.NotFound: no such entry > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(345)create_instance() -> self.start_creation(runtime=30) (Pdb) n --Return-- > /usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py(345)create_instance()->None -> self.start_creation(runtime=30) (Pdb) n ipalib.errors.NotFound: no such entry > /usr/lib/python3.6/site-packages/ipaserver/install/server/install.py(801)install() -> setup_pkinit=not options.no_pkinit) (Pdb) n --Return-- > /usr/lib/python3.6/site-packages/ipaserver/install/server/install.py(801)install()->None -> setup_pkinit=not options.no_pkinit) (Pdb) n ipalib.errors.NotFound: no such entry > /usr/lib/python3.6/site-packages/ipaserver/install/server/install.py(253)decorated() -> func(installer) (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/server/install.py(255)decorated() -> except KeyboardInterrupt: (Pdb) n > /usr/lib/python3.6/site-packages/ipaserver/install/server/install.py(270)decorated() -> if not success and installer._installation_cleanup: (Pdb) n --Return-- > /usr/lib/python3.6/site-packages/ipaserver/install/server/install.py(270)decorated()->None -> if not success and installer._installation_cleanup: (Pdb) n ipalib.errors.NotFound: no such entry > /usr/lib/python3.6/site-packages/ipaserver/install/server/__init__.py(602)main() -> master_install(self) (Pdb) n no such entry The ipa-server-install command failed. See /var/log/ipaserver-install.log for more information Exception ignored in: <async_generator object _ag at 0x7f8c198c3250> Traceback (most recent call last): File "/usr/lib64/python3.6/types.py", line 27, in _ag File "/usr/lib64/python3.6/bdb.py", line 53, in trace_dispatch File "/usr/lib64/python3.6/bdb.py", line 79, in dispatch_call File "/usr/lib64/python3.6/bdb.py", line 176, in break_anywhere File "/usr/lib64/python3.6/bdb.py", line 36, in canonic AttributeError: 'NoneType' object has no attribute 'abspath'
Hello there,
soooo. After many struggles and tests and other things, I finally know why it was failing. Yes. was.
The issue was due to an small error in the network configuration on the node: the IPv6 wasn't properly attached to the interface, and this prevented the installer to deploy correctly, as it was apparently passing over ipv6 instead of v4.
So the error message is misleading, and should more read something like "unable to connect" or "connection timeout", or something like that, instead of the "not found".
I can now deploy my 3-nodes freeIPA, instead of knocking my head against the wall with the master-master replication for slapd :D.
Cheers,
C.
Metadata Update from @rcritten: - Issue close_status updated to: worksforme - Issue status updated to: Closed (was: Open)
Login to comment on this ticket.