Issue #8117: official server container fails to initialize on Fedora 30 - freeipa

Ah, sorry about that. If you can't transfer this issue, I'm happy to close this and reopen one against freeipa-container.

rcritten commented 4 years ago

No worries, we don't expect everyone to know about all the sister projects. Let's give them a chance to respond and we can move it if necessary.

First about the versions. As of today, that freeipa/freeipa-server(:latest) is Fedora 31 container.

@tdudlak, any idea why its size as shown on https://hub.docker.com/r/freeipa/freeipa-server/tags (c633b755e4e6 285.9 MB) differs from the size of the image tagged fedora-31 (bb22a81d6995 288.15 MB)?

May I assume that CONT='sudo podman'? Or how are you running the container?

The freeipa-client version is (I assume) on the host, so that should not be relevant to the investivation.

For the chance that the problem is caused by the same hostname on the host and in the container, can you try to run tests/run-partial-tests.sh Dockerfile.fedora-31, or if you are using podman, docker='sudo podman' tests/run-partial-tests.sh Dockerfile.fedora-31?

In general though, the ipaserver-install.log says

2019-11-08T15:55:03Z DEBUG Updated 1
2019-11-08T15:55:03Z DEBUG Destroyed connection context.ldap2_140368789665424
2019-11-08T15:55:03Z ERROR Upgrade failed with no such entry
2019-11-08T15:55:03Z DEBUG Traceback (most recent call last):
  File "/usr/lib/python3.7/site-packages/ipapython/ipaldap.py", line 1076, in error_handler
    yield
  File "/usr/lib/python3.7/site-packages/ipapython/ipaldap.py", line 1697, in update_entry
    self.conn.modify_s(str(entry.dn), modlist)
  File "/usr/lib64/python3.7/site-packages/ldap/ldapobject.py", line 629, in modify_s
    return self.modify_ext_s(dn,modlist,None,None)
  File "/usr/lib64/python3.7/site-packages/ldap/ldapobject.py", line 602, in modify_ext_s
    resp_type, resp_data, resp_msgid, resp_ctrls = self.result3(msgid,all=1,timeout=self.timeout)
  File "/usr/lib64/python3.7/site-packages/ldap/ldapobject.py", line 749, in result3
    resp_ctrl_classes=resp_ctrl_classes
  File "/usr/lib64/python3.7/site-packages/ldap/ldapobject.py", line 756, in result4
    ldap_result = self._ldap_call(self._l.result4,msgid,all,timeout,add_ctrls,add_intermediates,add_extop)
  File "/usr/lib64/python3.7/site-packages/ldap/ldapobject.py", line 329, in _ldap_call
    reraise(exc_type, exc_value, exc_traceback)
  File "/usr/lib64/python3.7/site-packages/ldap/compat.py", line 44, in reraise
    raise exc_value
  File "/usr/lib64/python3.7/site-packages/ldap/ldapobject.py", line 313, in _ldap_call
    result = func(*args,**kwargs)
ldap.NO_SUCH_OBJECT: {'desc': 'No such object'}

During handling of the above exception, another exception occurred:

which looks like the dirsrv service died or became unavailable (unless that object the traceback talks about is actually an LDAP object and not LDAP connection).

Could you check the journal (likely under /var/lib/ipa-data/var/log/journal/*) to see if there is something interesting about the services behaviour in general?

May I assume that CONT='sudo podman'?

Whoops, yes. It can be "podman" or "docker", I tried with both. I updated the description to set CONT.

The freeipa-client version is (I assume) on the host, so that should not be relevant to the investivation.

Ah, that's right. The server install log has the one in the container:

DEBUG IPA version 4.8.1-4.fc31

For the chance that the problem is caused by the same hostname on the host and in the container,

I tried with -h ipa.cockpit.lan now (host is still x0.cockpit.lan), this gives exactly the same error.

I grabbed the complete journal from the container. You asked about dirsrv, the last startup of it indeed shows something which may be interesting:

$ journalctl --file /var/lib/ipa-data/var/log/journal/e18fd534b015307be7121b04633f3f4c/system.journal  -u dirsrv@COCKPIT-LAN.service -ocat
[...]
Started 389 Directory Server COCKPIT-LAN..
[13/Nov/2019:06:36:22.132450544 +0000] - ERR - get_dom_sid - [file ipa_sidgen_common.c, line 75]: Internal search failed.
[13/Nov/2019:06:36:23.032587216 +0000] - ERR - _entryrdn_insert_key - Suffix "dc=cockpit,dc=lan" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[13/Nov/2019:06:36:23.116599897 +0000] - ERR - index_addordel_entry - database index operation failed BAD 1031, err=-30988 BDB0073 DB_NOTFOUND: No matching key/data pair found
[13/Nov/2019:06:36:23.154246731 +0000] - ERR - get_dom_sid - [file ipa_sidgen_common.c, line 75]: Internal search failed.
[13/Nov/2019:06:36:23.184224330 +0000] - ERR - get_dom_sid - [file ipa_sidgen_common.c, line 75]: Internal search failed.
[13/Nov/2019:06:36:23.216254078 +0000] - ERR - get_dom_sid - [file ipa_sidgen_common.c, line 75]: Internal search failed.
[13/Nov/2019:06:36:23.247018012 +0000] - ERR - get_dom_sid - [file ipa_sidgen_common.c, line 75]: Internal search failed.
[13/Nov/2019:06:36:23.278609622 +0000] - ERR - get_dom_sid - [file ipa_sidgen_common.c, line 75]: Internal search failed.
[13/Nov/2019:06:36:23.309029778 +0000] - ERR - get_dom_sid - [file ipa_sidgen_common.c, line 75]: Internal search failed.
[13/Nov/2019:06:36:23.340227866 +0000] - ERR - get_dom_sid - [file ipa_sidgen_common.c, line 75]: Internal search failed.
[13/Nov/2019:06:36:23.368319024 +0000] - ERR - get_dom_sid - [file ipa_sidgen_common.c, line 75]: Internal search failed.
[13/Nov/2019:06:36:23.396301764 +0000] - ERR - get_dom_sid - [file ipa_sidgen_common.c, line 75]: Internal search failed.
[13/Nov/2019:06:36:23.423469381 +0000] - ERR - slapi_entry_schema_check_ext - Entry "cn=ng,cn=alt,dc=cockpit,dc=lan" required attribute "objectclass" missing
[13/Nov/2019:06:36:23.457999893 +0000] - ERR - slapi_entry_schema_check_ext - Entry "cn=accounts,dc=cockpit,dc=lan" required attribute "objectclass" missing
[13/Nov/2019:06:36:23.503926548 +0000] - ERR - get_dom_sid - [file ipa_sidgen_common.c, line 75]: Internal search failed.
[13/Nov/2019:06:36:23.540569704 +0000] - ERR - get_dom_sid - [file ipa_sidgen_common.c, line 75]: Internal search failed.
[13/Nov/2019:06:36:23.570346960 +0000] - ERR - slapi_entry_schema_check_ext - Entry "cn=computers,cn=accounts,dc=cockpit,dc=lan" required attribute "objectclass" missing
[13/Nov/2019:06:36:23.603615878 +0000] - ERR - slapi_entry_schema_check_ext - Entry "cn=computers,cn=accounts,dc=cockpit,dc=lan" required attribute "objectclass" missing
[13/Nov/2019:06:36:23.637567557 +0000] - ERR - get_dom_sid - [file ipa_sidgen_common.c, line 75]: Internal search failed.
Stopping 389 Directory Server COCKPIT-LAN....

can you try to run tests/run-partial-tests.sh Dockerfile.fedora-31

I did this on a current Fedora 30 VM:

# git clone https://github.com/freeipa/freeipa-container/; cd freeipa-container/
# docker=podman tests/run-partial-tests.sh Dockerfile.fedora-31
[...]
Executing tests/systemd-container-ipa-server-install-data.sh freeipa-server-container-fedora-31 docker-diff-minimal-fedora-23.out
[...]
Done configuring the web interface (httpd).
Configuring Kerberos KDC (krb5kdc)
  [1/1]: installing X509 Certificate for PKINIT
Done configuring Kerberos KDC (krb5kdc).
Applying LDAP updates
Upgrading IPA:. Estimated time: 1 minute 30 seconds
  [1/10]: stopping directory server
  [2/10]: saving configuration
  [3/10]: disabling listeners
  [4/10]: enabling DS global lock
  [5/10]: disabling Schema Compat
  [6/10]: starting directory server
  [7/10]: upgrading server
Parent DN of cn=anonymous-limits,cn=etc,dc=example,dc=test may not exist, cannot create the entry
Add failure Operations error: 
Parent DN of cn=usermap,cn=selinux,dc=example,dc=test may not exist, cannot create the entry
Parent DN of cn=Managed Entries,cn=etc,dc=example,dc=test may not exist, cannot create the entry
Parent DN of cn=Templates,cn=Managed Entries,cn=etc,dc=example,dc=test may not exist, cannot create the entry
Parent DN of cn=Definitions,cn=Managed Entries,cn=etc,dc=example,dc=test may not exist, cannot create the entry
Parent DN of cn=ng,cn=alt,dc=example,dc=test may not exist, cannot create the entry
Add failure missing required attribute "objectclass"
Parent DN of dc=example,dc=test may not exist, cannot create the entry
Parent DN of cn=computers,cn=accounts,dc=example,dc=test may not exist, cannot create the entry
Parent DN of cn=computers,cn=accounts,dc=example,dc=test may not exist, cannot create the entry
Upgrade failed with no such entry
  [error] RuntimeError: no such entry
  [cleanup]: stopping directory server
  [cleanup]: restoring configuration
Update failed: no such entry
The ipa-server-install command failed. See /var/log/ipaserver-install.log for more information
Error: non zero exit code: 1: OCI runtime error

/var/log/ipaserver-install.log shows exactly the same errors as in my reproducer above. So indeed your integration tests detect this. :grin:

I just tried on Fedora 31 and I'm getting issue within dogtag installer with permissions in an attempt to write to /etc/sysconfig/pki/tomcat/pki-tomcat/ca/default.cfg

Configuring certificate server (pki-tomcatd). Estimated time: 3 minutes
  [1/29]: configuring certificate server instance
Failed to configure CA instance: CalledProcessError(Command ['/usr/sbin/pkispawn', '-s', 'CA', '-f', '/tmp/tmpte9uv2n7'] returned non-zero exit status 1: 'ERROR   : pkihelper      OSError:  [Errno 13] Permission denied: \'/etc/sysconfig/pki/tomcat/pki-tomcat/ca/default.cfg\'!\nERROR   : pkispawn       PermissionError: [Errno 13] Permission denied: \'/etc/sysconfig/pki/tomcat/pki-tomcat/ca/default.cfg\'\n  File "/usr/lib/python3.7/site-packages/pki/server/pkispawn.py", line 546, in main\n    scriptlet.spawn(deployer)\n  File "/usr/lib/python3.7/site-packages/pki/server/deployment/scriptlets/infrastructure_layout.py", line 64, in spawn\n    deployer.mdict[\'pki_default_deployment_cfg_replica\'])\n  File "/usr/lib/python3.7/site-packages/pki/server/deployment/pkihelper.py", line 1460, in copy\n    shutil.copy2(old_name, new_name)\n  File "/usr/lib64/python3.7/shutil.py", line 267, in copy2\n    copystat(src, dst, follow_symlinks=follow_symlinks)\n  File "/usr/lib64/python3.7/shutil.py", line 209, in copystat\n    _copyxattr(src, dst, follow_symlinks=follow)\n  File "/usr/lib64/python3.7/shutil.py", line 165, in _copyxattr\n    os.setxattr(dst, name, value, follow_symlinks=follow_symlinks)\n\n')
See the installation logs and the following files/directories for more information:
  /var/log/pki/pki-tomcat
  [error] RuntimeError: CA configuration failed.
CA configuration failed.
The ipa-server-install command failed. See /var/log/ipaserver-install.log for more information
Error: non zero exit code: 1: OCI runtime error

@martinpitt, could you try with docker='sudo podman'. With just docker=podman you are running a rootless container and we haven't really tested that yet.

tdudlak commented 4 years ago

First about the versions. As of today, that freeipa/freeipa-server(:latest) is Fedora 31 container.
@tdudlak, any idea why its size as shown on https://hub.docker.com/r/freeipa/freeipa-server/tags (c633b755e4e6 285.9 MB) differs from the size of the image tagged fedora-31 (bb22a81d6995 288.15 MB)?

The triggered run to update images failed for Dockerfile but passed for Dockerfile.fedora-31:
Error: Failed to download metadata for repo 'fedora'

May I assume that CONT='sudo podman'? Or how are you running the container?
The freeipa-client version is (I assume) on the host, so that should not be relevant to the investivation.

The triggered run to update images failed for Dockerfile but passed for Dockerfile.fedora-31:
Error: Failed to download metadata for repo 'fedora'

Isn't that just a temporary networking issue, so forcing the build to rerun should solve that?

@adelton : This was running as root (it's our test VMs with temporary overlays, so we have no hesitation to do everything as root there :smile: ). I haven't tested this as a rootless container, as it doesn't make much sense for our use case.

@abbra : You apparently got much further on F31 than me -- both docker and podman fail very early for me. Did you do something special there, like reverting the switch to cgroupsv2 or so?

For the record, I am using systemd.unified_cgroup_hierarchy=0 on my Fedora 31, primarily to be able to test with docker as well.
But podman should work with v2 -- what is the early failure that you refer to? That Update failed: no such entry from comment 0, or something else?

@martinpitt I've got everything working on F31 with docker='sudo podman' -- I got it container built and successfully passing the tests. I failed in tomcat processing for docker=podman, e.g. in rootless podman container.

And I do use default F31 setup which means it is cgroups v2.

@adelton: Yes, podman in general works with cgroupsv2 (I'm counting on it -- I use toolbox all the time on OSTreee). But with the freeipa container specifically it fails with Failed to create /machine.slice/libpod-[.].scope/init.scope control group: Read-only file system (see original description).

@martinpitt I don't get that problem with cgroupsv2. Do you get it with 'sudo podman' too?

@martinpitt any investigation with regards my question?

@abbra: All of my container invocations happen as root, i. e. there's no user podman involved. I tried the reproducer again on an up to date Fedora 31 VM (from a fairly standard virt-install), and I'm still getting the same error:

systemd v243-4.gitef67743.fc31 running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=unified)
Detected virtualization container-other.
Detected architecture x86-64.
Set hostname to <ipa.cockpit.lan>.
Initializing machine ID from random generator.
Failed to create /machine.slice/libpod-0a4067b0d0799bb50670bffcbb1c54c978159be9355704d98e0ada560163f5ff.scope/init.scope control group: Read-only file system
Failed to allocate manager object: Read-only file system
[!!!!!!] Failed to allocate manager object.
Exiting PID 1...

This is with using a different container host name (-h) than the host, and happens with and without SELinux.

@martinpitt, what does

podman run --rm -ti --name systemd registry.fedoraproject.org/fedora:31 /usr/sbin/init

show on your machine?

@adelton: Exactly the same issue (see below). Anyway, note that the systemd failure under cgroupsv2 is unrelated to this bug report, which is about the IPA initialization failing. (I. e. in Fedora 30).

# podman run --rm -ti --name systemd registry.fedoraproject.org/fedora:31 /usr/sbin/init
Trying to pull registry.fedoraproject.org/fedora:31...
Getting image source signatures
Copying blob c0a89efa8873 done
Copying config aaaa3e1d6a done
Writing manifest to image destination
Storing signatures
systemd v243-4.gitef67743.fc31 running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=unified)
Detected virtualization container-other.
Detected architecture x86-64.

Welcome to Fedora 31 (Container Image)!

Set hostname to <b51f15a591c8>.
Initializing machine ID from random generator.
Failed to create /machine.slice/libpod-b51f15a591c8419688931296052f39c48ac4c4182f652772fc7a59556836fea1.scope/init.scope control group: Permission denied
Failed to allocate manager object: Permission denied
[!!!!!!] Failed to allocate manager object.
Exiting PID 1...