Bug 1677027

Created attachment 1534545 [details]
Full tarball of /var/log from a failed attempt

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.

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

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

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)

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

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.

This looks like a generic Python issue.

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

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 ?

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

(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.

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

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

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!

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.

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."

Francois will handle it upstream.

Switching Prio to urgent as it is a Beta blocker

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

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

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

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

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

(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.

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

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?

@fcami openQA will test it for us with the next Rawhide compose.

We still don't have a Rawhide compose, but we *did* get a Branched compose, and FreeIPA tests passed in that, so I'm gonna say this is indeed fixed. Thanks.