Bug 1678794

Summary:	FreeIPA server deployment fails due to 'Permission denied' error under /tmp during pki-tomcatd deployment
Product:	[Fedora] Fedora	Reporter:	François Cami <fcami>
Component:	freeipa	Assignee:	IPA Maintainers <ipa-maint>
Status:	CLOSED ERRATA	QA Contact:	Fedora Extras Quality Assurance <extras-qa>
Severity:	urgent	Docs Contact:
Priority:	urgent
Version:	28	CC:	abokovoy, contribs, ipa-maint, jcholast, jhrozek, pvoborni, rcritten, ssorce, twoerner
Target Milestone:	---
Target Release:	---
Hardware:	All
OS:	All
Whiteboard:	openqa
Fixed In Version:	freeipa-4.7.2-1.1.fc28	Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:	1677027	Environment:
Last Closed:	2019-03-01 23:10:37 UTC	Type:	---
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:
Bug Depends On:	1677027
Bug Blocks:

Description François Cami 2019-02-19 15:46:38 UTC

Notes: Bug #1677027 was cloned to f28 because a f28-based FreeIPA container image will probably fail to run on f30 due to the systemd change referenced below.

+++ This bug was initially created as a clone of Bug #1677027 +++

FreeIPA server deployment fails in current Rawhide (Fedora-Rawhide-20190213.n.0) due to a 'Permission denied' error during pki-tomcatd deployment:

2019-02-13T12:40:33Z DEBUG Configuring certificate server (pki-tomcatd). Estimated time: 3 minutes
2019-02-13T12:40:33Z DEBUG   [1/28]: configuring certificate server instance
2019-02-13T12:40:33Z DEBUG Traceback (most recent call last):
  File "/usr/lib/python3.7/site-packages/ipaserver/install/service.py", line 605, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python3.7/site-packages/ipaserver/install/service.py", line 591, in run_step
    method()
  File "/usr/lib/python3.7/site-packages/ipaserver/install/cainstance.py", line 665, in __spawn_instance
    with open(cfg_file, "w") as f:
PermissionError: [Errno 13] Permission denied: '/tmp/tmp7kyeiep5'

This broke some time between Fedora-Rawhide-20190121.n.1 and 20190213.n.0; I can't be more specific as we had no composes between 20190121.n.1 and 20190211.n.0, and the tests failed in the few composes from 20190211.n.0 till now for other reasons.

Proposing as a Beta blocker per Basic criterion "It must be possible to configure a Fedora Server system installed according to the above criteria as a FreeIPA domain controller, using the official deployment tools provided in the distribution FreeIPA packages..." - https://fedoraproject.org/wiki/Basic_Release_Criteria#FreeIPA_server_requirements

--- Additional comment from Adam Williamson on 2019-02-13 19:39 UTC ---



--- Additional comment from Adam Williamson on 2019-02-13 19:40:34 UTC ---

This doesn't immediately appear to be an SELinux issue, BTW, as no denials are logged anywhere. It could *possibly* be a noaudit denial I guess.

--- Additional comment from Adam Williamson on 2019-02-13 20:04:23 UTC ---

systemd 241 landed during the timeframe in question, so CCing zbyszek in case it may be involved.

--- Additional comment from Endi Sukma Dewata on 2019-02-13 21:34:09 UTC ---

Since the error happens in IPA's Python library, possibly before pkispawn execution, I'm moving this bug to freeipa component.

--- Additional comment from Alexander Bokovoy on 2019-02-14 07:58:11 UTC ---

We need don't audit rules logging to be shown. What happens is that we are unable to write to a temporary file in /tmp while we were writing there just fine before that. /tmp is tmpfs in Rawhide and is not limited by itself so unless we reach some weird state where RAM is exhausted on the node, memory limit should not be an issue:

# mount |grep /tmp
tmpfs on /tmp type tmpfs (rw,nosuid,nodev,seclabel)

--- Additional comment from François Cami on 2019-02-14 12:55:42 UTC ---

It can be reproduced even with SELinux disabled.

-rw------- 1 pkiuser pkiuser  0 Feb 14 13:51 tmp9dstiaa8

2019-02-14T12:51:53Z DEBUG Configuring certificate server (pki-tomcatd). Estimated time: 3 minutes
2019-02-14T12:51:53Z DEBUG   [1/28]: configuring certificate server instance
2019-02-14T12:51:53Z DEBUG Traceback (most recent call last):
  File "/usr/lib/python3.7/site-packages/ipaserver/install/service.py", line 605, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python3.7/site-packages/ipaserver/install/service.py", line 591, in run_step
    method()
  File "/usr/lib/python3.7/site-packages/ipaserver/install/cainstance.py", line 665, in __spawn_instance
    with open(cfg_file, "w") as f:
PermissionError: [Errno 13] Permission denied: '/tmp/tmp9dstiaa8'

2019-02-14T12:51:53Z DEBUG   [error] PermissionError: [Errno 13] Permission denied: '/tmp/tmp9dstiaa8'
2019-02-14T12:51:53Z DEBUG Removing /root/.dogtag/pki-tomcat/ca
2019-02-14T12:51:53Z DEBUG   File "/usr/lib/python3.7/site-packages/ipapython/admintool.py", line 179, in execute
    return_value = self.run()
  File "/usr/lib/python3.7/site-packages/ipapython/install/cli.py", line 347, in run
    return cfgr.run()
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 360, in run
    return self.execute()
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 386, in execute
    for rval in self._executor():
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 431, in __runner
    exc_handler(exc_info)
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 460, in _handle_execute_exception
    self._handle_exception(exc_info)
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 450, in _handle_exception
    six.reraise(*exc_info)
  File "/usr/lib/python3.7/site-packages/six.py", line 693, in reraise
    raise value
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 421, in __runner
    step()
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 418, in <lambda>
    step = lambda: next(self.__gen)
  File "/usr/lib/python3.7/site-packages/ipapython/install/util.py", line 81, in run_generator_with_yield_from
    six.reraise(*exc_info)
  File "/usr/lib/python3.7/site-packages/six.py", line 693, in reraise
    raise value
  File "/usr/lib/python3.7/site-packages/ipapython/install/util.py", line 59, in run_generator_with_yield_from
    value = gen.send(prev_value)
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 655, in _configure
    next(executor)
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 431, in __runner
    exc_handler(exc_info)
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 460, in _handle_execute_exception
    self._handle_exception(exc_info)
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 518, in _handle_exception
    self.__parent._handle_exception(exc_info)
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 450, in _handle_exception
    six.reraise(*exc_info)
  File "/usr/lib/python3.7/site-packages/six.py", line 693, in reraise
    raise value
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 515, in _handle_exception
    super(ComponentBase, self)._handle_exception(exc_info)
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 450, in _handle_exception
    six.reraise(*exc_info)
  File "/usr/lib/python3.7/site-packages/six.py", line 693, in reraise
    raise value
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 421, in __runner
    step()
  File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 418, in <lambda>
    step = lambda: next(self.__gen)
  File "/usr/lib/python3.7/site-packages/ipapython/install/util.py", line 81, in run_generator_with_yield_from
    six.reraise(*exc_info)
  File "/usr/lib/python3.7/site-packages/six.py", line 693, in reraise
    raise value
  File "/usr/lib/python3.7/site-packages/ipapython/install/util.py", line 59, in run_generator_with_yield_from
    value = gen.send(prev_value)
  File "/usr/lib/python3.7/site-packages/ipapython/install/common.py", line 65, in _install
    for unused in self._installer(self.parent):
  File "/usr/lib/python3.7/site-packages/ipaserver/install/server/__init__.py", line 550, in main
    master_install(self)
  File "/usr/lib/python3.7/site-packages/ipaserver/install/server/install.py", line 253, in decorated
    func(installer)
  File "/usr/lib/python3.7/site-packages/ipaserver/install/server/install.py", line 842, in install
    ca.install_step_0(False, None, options, custodia=custodia)
  File "/usr/lib/python3.7/site-packages/ipaserver/install/ca.py", line 318, in install_step_0
    use_ldaps=standalone)
  File "/usr/lib/python3.7/site-packages/ipaserver/install/cainstance.py", line 484, in configure_instance
    self.start_creation(runtime=runtime)
  File "/usr/lib/python3.7/site-packages/ipaserver/install/service.py", line 605, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python3.7/site-packages/ipaserver/install/service.py", line 591, in run_step
    method()
  File "/usr/lib/python3.7/site-packages/ipaserver/install/cainstance.py", line 665, in __spawn_instance
    with open(cfg_file, "w") as f:

2019-02-14T12:51:53Z DEBUG The ipa-server-install command failed, exception: PermissionError: [Errno 13] Permission denied: '/tmp/tmp9dstiaa8'
2019-02-14T12:51:53Z ERROR [Errno 13] Permission denied: '/tmp/tmp9dstiaa8'
2019-02-14T12:51:53Z ERROR The ipa-server-install command failed. See /var/log/ipaserver-install.log for more information

--- Additional comment from François Cami on 2019-02-14 15:26:11 UTC ---

so the following:

#!/usr/bin/python3

import tempfile
import os
import pwd

if __name__ == "__main__":

    (cfg_fd, cfg_file) = tempfile.mkstemp()
    os.close(cfg_fd)
    pent = pwd.getpwnam("pkiuser")
    os.chown(cfg_file, pent.pw_uid, pent.pw_gid)
    try:
        with open(cfg_file, "w") as f:
            print ("file opened")
    except Exception as e:
        print ("failure")
#    os.remove(cfg_file)


works in f29, but not on rawhide.

--- Additional comment from Alexander Bokovoy on 2019-02-14 15:27:32 UTC ---

This looks like a generic Python issue.

--- Additional comment from François Cami on 2019-02-14 15:31:57 UTC ---

In fact if I use vim on that file (/tmp/foo, pkiuser:pkiuser, 600) I cannot write to it (e.g. :x fails).

--- Additional comment from Alexander Bokovoy on 2019-02-14 15:39:03 UTC ---

Yes, I straced the reproducer and it boils down to

openat(AT_FDCWD, "/tmp/foobar", O_WRONLY|O_CREAT|O_TRUNC, 0666) = -1 EACCES (Permission denied)

E.g. opening an existing file for write fails on /tmp in Rawhide.

Florian, could you please help us? Could it be related to https://bugzilla.redhat.com/show_bug.cgi?id=1590228 ?

--- Additional comment from François Cami on 2019-02-14 15:40:35 UTC ---

For good measure, this also happens if I boot my rawhide userspace with the latest f29 kernel ( 4.20.7-200.fc29.x86_64 ).

--- Additional comment from Florian Weimer on 2019-02-14 15:55:45 UTC ---

(In reply to Alexander Bokovoy from comment #10)
> Yes, I straced the reproducer and it boils down to
> 
> openat(AT_FDCWD, "/tmp/foobar", O_WRONLY|O_CREAT|O_TRUNC, 0666) = -1 EACCES
> (Permission denied)
> 
> E.g. opening an existing file for write fails on /tmp in Rawhide.
> 
> Florian, could you please help us?

I don't think so.  Something must have happened during the boot process that causes this, like a seccomp filter or some very strange settings for the /tmp mount?

François' experiment from comment 11 seems to rule out a recent kernel change.

> Could it be related to
> https://bugzilla.redhat.com/show_bug.cgi?id=1590228 ?

No, current strace (like the version you used) would show mode zero, not mode 0666 in this case, and O_TMPFILE isn't even involved.

What does this show?

# umask
# sudo sysctl -a | grep protected

I wonder if the defaults have changed somewhere.

--- Additional comment from Alexander Bokovoy on 2019-02-14 15:59:33 UTC ---

This is my Rawhide system

# uname -r
5.0.0-0.rc4.git3.1.fc30.x86_64
# rpm -q glibc
glibc-2.29-7.fc30.x86_64
# umask
0022
# sysctl -a | grep protected
fs.protected_fifos = 1
fs.protected_hardlinks = 1
fs.protected_regular = 1
fs.protected_symlinks = 1

--- Additional comment from Alexander Bokovoy on 2019-02-14 16:01:02 UTC ---

On F29 (not so updated):

$ uname -r
4.19.13-300.fc29.x86_64

$ sudo sysctl -a | grep protected
fs.protected_fifos = 0
fs.protected_hardlinks = 1
fs.protected_regular = 0
fs.protected_symlinks = 1

--- Additional comment from François Cami on 2019-02-14 16:01:18 UTC ---

umask is still 0022

f29:
# sysctl -a | grep protected
fs.protected_fifos = 0
fs.protected_hardlinks = 1
fs.protected_regular = 0
fs.protected_symlinks = 1

rawhide:
# sysctl -a | grep protected
fs.protected_fifos = 1
fs.protected_hardlinks = 1
fs.protected_regular = 1
fs.protected_symlinks = 1

Switching fs.protected_regular to 0 fixed the bug. Thanks Florian!

--- Additional comment from Alexander Bokovoy on 2019-02-14 16:04:52 UTC ---

Ok, so according to https://www.kernel.org/doc/Documentation/sysctl/fs.txt

fs.protected_regular:

When set to "1" don't allow O_CREAT open on regular files that we
don't own in world writable sticky directories, unless they are
owned by the owner of the directory.

This affects root as not being able to write to temporary files. I think we need to refactor how we create these files in FreeIPA installer -- we probably should create it sa root and then chown to pkiuser.

--- Additional comment from Adam Williamson on 2019-02-14 16:05:09 UTC ---

And indeed, as I speculated, this is a systemd change:

https://www.phoronix.com/scan.php?page=news_item&px=Systemd-241-Linux-419-Sysctl

(sorry for Phoronix reference, it was the first relevant thing that came up on Google, but it happens to be actually correct in this case!)

"The restricted O_CREAT of FIFOs and regular files is not enforced by the kernel by default as it could be considered a breaking change but with systemd 241+ it sets the fs.protected_regular and fs.protected_fifos sysctls to enabled for having said functionality, similar to systemd's enforcing of hardlink/symlink protection."

--- Additional comment from Alexander Bokovoy on 2019-02-14 16:16:47 UTC ---

Francois will handle it upstream.

--- Additional comment from François Cami on 2019-02-15 15:39:42 UTC ---

Switching Prio to urgent as it is a Beta blocker

--- Additional comment from François Cami on 2019-02-15 15:47:43 UTC ---

Upstream ticket:
https://pagure.io/freeipa/issue/7866

--- Additional comment from François Cami on 2019-02-15 15:53:21 UTC ---

Internal JIRA: https://projects.engineering.redhat.com/browse/FREEIPA-2555
Assigning to myself.

--- Additional comment from François Cami on 2019-02-18 10:38:50 UTC ---

PR: https://github.com/freeipa/freeipa/pull/2843

--- Additional comment from François Cami on 2019-02-19 00:24:27 UTC ---

Fixed upstream
master: https://pagure.io/freeipa/c/5525322817c736d8851661a5bfedfdd5c794e5c8

Adam, I'll rebuild freeipa for rawhide/f30 tomorrow morning.

--- Additional comment from Florence Blanc-Renaud on 2019-02-19 06:12:11 UTC ---

Fixed upstream
ipa-4-7:
https://pagure.io/freeipa/c/87496d647706462fa8a10bbea5637104153146b2

--- Additional comment from Lukas Slebodnik on 2019-02-19 09:18:09 UTC ---

(In reply to François Cami from comment #23)
> Fixed upstream
> master: https://pagure.io/freeipa/c/5525322817c736d8851661a5bfedfdd5c794e5c8
> 
> Adam, I'll rebuild freeipa for rawhide/f30 tomorrow morning.

This should be fixed also in f28 and f29 because the same problem is also when using freeipa server  in container. And obviously it make sense to use more stable container on fedora rawhide.

--- Additional comment from François Cami on 2019-02-19 11:15:44 UTC ---

freeipa.spec currently FTBFS on rawhide due to https://bugzilla.redhat.com/show_bug.cgi?id=1678670

--- Additional comment from François Cami on 2019-02-19 15:21:43 UTC ---

Hello Adam,
I've just built freeipa-4.7.2-5.fc30 which contains both patches for #1678670 (FTBS) and #1677027 (this one).
https://koji.fedoraproject.org/koji/taskinfo?taskID=32907535 is all yours, can you confirm installing FreeIPA works for you now?

Comment 1 Alexander Bokovoy 2019-02-19 18:46:00 UTC

I submitted https://koji.fedoraproject.org/koji/buildinfo?buildID=1213736 with fixes for Fedora 28.

Comment 2 Fedora Update System 2019-02-20 10:11:06 UTC

freeipa-4.7.2-1.1.fc28 has been submitted as an update to Fedora 28. https://bodhi.fedoraproject.org/updates/FEDORA-2019-a4c134b46a

Comment 3 Fedora Update System 2019-02-21 01:28:08 UTC

freeipa-4.7.2-1.1.fc28 has been pushed to the Fedora 28 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2019-a4c134b46a

Comment 4 Fedora Update System 2019-03-01 23:10:37 UTC

freeipa-4.7.2-1.1.fc28 has been pushed to the Fedora 28 stable repository. If problems still persist, please make note of it in this bug report.