Bug 1871869

> We have wrapper being NULL, so dereferencing fails ...
> The "wrapper" comes from frame 1 ("invoke_closure->closure") which is NULL here (this isn't expected at all).

The backtrace looks like it's deep in GLib; I'm changing the component so the glib maintainers can take a look.
Let me know if I can help on the Python side; feel free to assign it back.

> Here we see that setroubleshootd also stats GLib.py and starts using compiled GLib.cpython-36.pyc code.
> However, later we see GLib.py is read for some unknown reason even though the last "stat()" at timestamp 08:23:09.232603 (see "STAT ON GLib.py AGAIN" token above) is identical to all other stats, hence there is no modification of GLib.py that could explain Python "decides" to read it now and stop using GLib.cpython-36.pyc code.

One reason Python reads the .py file is to display an error message: the backtrace is displayed with lines of the original source (.py), even if the bytecode cache (.pyc) is used for execution.
Reading the file doesn't necessarily mean that the already imported module is replaced by newly compiled code.

I can now reproduce at will.
All you need is to set up "noexec" on /tmp, /var/tmp and /dev/shm mount points:
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
tmpfs	/tmp		tmpfs   defaults,nodev,nosuid,noexec 0 0
tmpfs	/var/tmp	tmpfs   defaults,nodev,nosuid,noexec 0 0
tmpfs	/dev/shm	tmpfs	nodev,nosuid,noexec	0 0
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

The strace of setroubleshootd shows it tries to create a temporary file under these locations to execute code, which fails due to having "noexec":
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
$ grep EPERM /tmp/setroubleshootd.strace 
5950  11:08:44.098864 mmap(NULL, 4096, PROT_READ|PROT_EXEC, MAP_SHARED, 6</tmp/#36349 (deleted)>, 0) = -1 EPERM (Operation not permitted) <0.000004>
5950  11:08:44.098928 mmap(NULL, 4096, PROT_READ|PROT_EXEC, MAP_SHARED, 6</var/tmp/#36350 (deleted)>, 0) = -1 EPERM (Operation not permitted) <0.000003>
5950  11:08:44.099070 mmap(NULL, 4096, PROT_READ|PROT_EXEC, MAP_SHARED, 6</dev/shm/#36351 (deleted)>, 0) = -1 EPERM (Operation not permitted) <0.000003>
5950  11:08:44.099462 mmap(NULL, 4096, PROT_READ|PROT_EXEC, MAP_SHARED, 7</dev/mqueue/ffiqJVA2R (deleted)>, 0) = -1 EPERM (Operation not permitted) <0.000004>
5950  11:08:44.099961 mmap(NULL, 4096, PROT_READ|PROT_EXEC, MAP_SHARED, 7</dev/mqueue/ffiWsuidr (deleted)>, 0) = -1 EPERM (Operation not permitted) <0.000003>
5950  11:08:44.101134 mmap(NULL, 4096, PROT_READ|PROT_EXEC, MAP_SHARED, 9</tmp/#36368 (deleted)>, 0) = -1 EPERM (Operation not permitted) <0.000003>
5950  11:08:44.101197 mmap(NULL, 4096, PROT_READ|PROT_EXEC, MAP_SHARED, 9</var/tmp/#36370 (deleted)>, 0) = -1 EPERM (Operation not permitted) <0.000003>
5950  11:08:44.101255 mmap(NULL, 4096, PROT_READ|PROT_EXEC, MAP_SHARED, 9</dev/shm/#36371 (deleted)>, 0) = -1 EPERM (Operation not permitted) <0.000002>
5950  11:08:44.101605 mmap(NULL, 4096, PROT_READ|PROT_EXEC, MAP_SHARED, 10</dev/mqueue/ffiaUxeo0 (deleted)>, 0) = -1 EPERM (Operation not permitted) <0.000003>
5950  11:08:44.101992 mmap(NULL, 4096, PROT_READ|PROT_EXEC, MAP_SHARED, 10</dev/mqueue/ffiqa6dzz (deleted)>, 0) = -1 EPERM (Operation not permitted) <0.000003>
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

This happens in the middle of parsing /proc/<pid>/mounts just after binding+listening on /var/run/setroubleshoot/setroubleshoot_server:
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
5950  11:08:44.098372 bind(5<UNIX:[36342]>, {sa_family=AF_UNIX, sun_path="/var/run/setroubleshoot/setroubleshoot_server"}, 47) = 0 <0.000025>
 :
5950  11:08:44.098442 listen(5<UNIX:[36342,"/var/run/setroubleshoot/setroubleshoot_server"]>, 5) = 0 <0.000003>
 :
5950  11:08:44.098683 openat(AT_FDCWD, "/proc/mounts", O_RDONLY) = 6</proc/5950/mounts> <0.000010>
5950  11:08:44.098707 fstat(6</proc/5950/mounts>, {st_dev=makedev(0, 4), st_ino=36348, st_mode=S_IFREG|0444, st_nlink=1, st_uid=986, st_gid=982, st_blksize=1024, st_blocks=0, st_size=0, st_atime=1599124124 /* 2020-09-03T11:08:44.098161186+0200 */, st_atime_nsec=98161186, st_mtime=1599124124 /* 2020-09-03T11:08:44.098161186+0200 */, st_mtime_nsec=98161186, st_ctime=1599124124 /* 2020-09-03T11:08:44.098161186+0200 */, st_ctime_nsec=98161186}) = 0 <0.000002>
 :
5950  11:08:44.098810 close(6</proc/5950/mounts>) = 0 <0.000003>
5950  11:08:44.098825 openat(AT_FDCWD, "/tmp", O_RDWR|O_EXCL|O_CLOEXEC|O_TMPFILE, 0700) = 6</tmp/#36349 (deleted)> <0.000012>
5950  11:08:44.098851 ftruncate(6</tmp/#36349 (deleted)>, 4096) = 0 <0.000003>
5950  11:08:44.098864 mmap(NULL, 4096, PROT_READ|PROT_EXEC, MAP_SHARED, 6</tmp/#36349 (deleted)>, 0) = -1 EPERM (Operation not permitted) <0.000004>
 :
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

Then /etc/mtab is read and temporary file is created again, which ends up having the "could not allocate closure" message:
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
 :
5950  11:08:44.100143 sendmsg(6<UNIX:[36354]>, {msg_name={sa_family=AF_UNIX, sun_path="/run/systemd/journal/socket"}, msg_namelen=29, msg_iov=[{iov_base="GLIB_OLD_LOG_API", iov_len=16}, {iov_base="=", iov_len=1}, {iov_base="1", iov_len=1}, {iov_base="\n", iov_len=1}, {iov_base="MESSAGE", iov_len=7}, {iov_base="\n", iov_len=1}, {iov_base="\33\0\0\0\0\0\0\0", iov_len=8}, {iov_base="could not allocate closure\n", iov_len=27}, {iov_base="\n", iov_len=1}, {iov_base="PRIORITY", iov_len=8}, {iov_base="=", iov_len=1}, {iov_base="4", iov_len=1}, {iov_base="\n", iov_len=1}], msg_iovlen=13, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 74 <0.000360>
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

# strings /usr/lib64/libgirepository-1.0.so.1.0.0 | grep "could not alloca"
could not allocate closure

Sorry, moving this back to gygobject3 for the following reason:

1. We have g_callable_info_prepare_closure (gobject-introspection package) just call ffi_closure_alloc()

-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
364 ffi_closure *
365 g_callable_info_prepare_closure (GICallableInfo       *callable_info,
366                                  ffi_cif              *cif,
367                                  GIFFIClosureCallback  callback,
368                                  gpointer              user_data)
369 {
 :
380   closure = ffi_closure_alloc (sizeof (GIClosureWrapper), &exec_ptr);
381   if (!closure)
382     {
383       g_warning ("could not allocate closure\n");
384       return NULL;
385     }
 :
407   /* Return exec_ptr, which points to the same underlying memory as
408    * closure, but via an executable-non-writable mapping.
409    */
410   return exec_ptr;
411 }
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

We return NULL because ffi_closure_alloc() failed.

2. Caller of g_callable_info_prepare_closure() is _pygi_make_native_closure()

-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
653 PyGICClosure*
654 _pygi_make_native_closure (GICallableInfo* info,
655                            GIScopeType scope,
656                            PyObject *py_function,
657                            gpointer py_user_data)
658 {
 :
675     fficlosure =
676         g_callable_info_prepare_closure (info, &closure->cif, _pygi_closure_handle,
677                                          closure);
678     closure->closure = fficlosure;
 :
684     return closure;
685 }
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

On line 678, we see the assignment to "closure" field without taking care of the result (fficlosure == NULL here).

I would expect the function to "return NULL" on "fficlosure == NULL" condition (after freeing "closure" of course).

Otherwise a condition should be evaluated to not call blindly g_callable_info_free_closure() in _pygi_invoke_closure_free() on line 639:
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
634 void _pygi_invoke_closure_free (gpointer data)
635 {
636     PyGICClosure* invoke_closure = (PyGICClosure *) data;
637 
638     g_callable_info_free_closure (invoke_closure->info,
639                                   invoke_closure->closure);
 :
650 }
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

This has to be some kind of permission issue. Any selinux denials in the logs?

Here is the relevant code from ffi_closure_alloc:


  /* Primary mapping is RW, but request permission to switch to PROT_EXEC later. */
  prot = PROT_READ | PROT_WRITE | PROT_MPROTECT(PROT_EXEC);
  dataseg = mmap(NULL, rounded_size, prot, MAP_ANON | MAP_PRIVATE, -1, 0);
  if (dataseg == MAP_FAILED)
    return NULL;

  /* Create secondary mapping and switch it to RX. */
  codeseg = mremap(dataseg, rounded_size, NULL, rounded_size, MAP_REMAPDUP);
  if (codeseg == MAP_FAILED) {
    munmap(dataseg, rounded_size);
    return NULL;
  }
  if (mprotect(codeseg, rounded_size, PROT_READ | PROT_EXEC) == -1) {
    munmap(codeseg, rounded_size);
    munmap(dataseg, rounded_size);
    return NULL;
  }


One of htese calls must fail.

There are no AVC denials, it's due to having "nosuid,noexec" on /tmp, /var/tmp and /dev/shm.

We have numerous customers having this kind of setup, this is apparently mandatory to meet STIG requirements.
See C#4 for the reproducer and C#6 for proposal.

I'm also hitting this bug on my Thinkpad laptop running RHEL 8.5 CSB. It's very easy to reproduce, just add the three lines below to /etc/fstab:

tmpfs                   /dev/shm                tmpfs   defaults,nodev,noexec,nosuid        0 0
tmpfs                   /tmp                tmpfs   defaults,nodev,noexec,nosuid        0 0
/var/tmp                   /var/tmp         none          bind,nodev,noexec,nosuid        0 0

Then remount these paths with the new options:

$ for path in '/dev/shm' '/tmp' '/var/tmp'; do sudo mount -o remount $path; done

Then run strace on setroubleshootd, and you will see the call to mmap() that fails:

$ sudo strace --decode-fds=path setroubleshootd --nofork 2>&1 | egrep '/tmp|/shm'
openat(AT_FDCWD, "/tmp", O_RDWR|O_EXCL|O_CLOEXEC|O_TMPFILE, 0700) = 6</tmp/#90450 (deleted)>
ftruncate(6</tmp/#90450 (deleted)>, 4096) = 0
mmap(NULL, 4096, PROT_READ|PROT_EXEC, MAP_SHARED, 6</tmp/#90450 (deleted)>, 0) = -1 EPERM (Operation not permitted)
close(6</tmp/#90450 (deleted)>)         = 0
openat(AT_FDCWD, "/var/tmp", O_RDWR|O_EXCL|O_CLOEXEC|O_TMPFILE, 0700) = 6</var/tmp/#8417060 (deleted)>
ftruncate(6</var/tmp/#8417060 (deleted)>, 4096) = 0
mmap(NULL, 4096, PROT_READ|PROT_EXEC, MAP_SHARED, 6</var/tmp/#8417060 (deleted)>, 0) = -1 EPERM (Operation not permitted)
close(6</var/tmp/#8417060 (deleted)>)   = 0
openat(AT_FDCWD, "/dev/shm", O_RDWR|O_EXCL|O_CLOEXEC|O_TMPFILE, 0700) = 6</dev/shm/#93200 (deleted)>
ftruncate(6</dev/shm/#93200 (deleted)>, 4096) = 0
mmap(NULL, 4096, PROT_READ|PROT_EXEC, MAP_SHARED, 6</dev/shm/#93200 (deleted)>, 0) = -1 EPERM (Operation not permitted)
close(6</dev/shm/#93200 (deleted)>)     = 0

These mmap calls do not fail when /dev/shm, /tmp, and /var/tmp are mounted with "exec" instead of "noexec". Comment #4 also has more details. Is there any other info I can provide to help move this ticket forward? Or please let me know if I can help test a fix.

To explain the use case for nounting these paths as "noexec", comment #11 is correct that it's compliance-related. The "SCAP Workbench" program is used to scan a system for known misconfigurations and other issues, based on security hardening content / checklists provided by the "scap-security-guide" package. Many of the available configuration profiles, including "DISA STIG with GUI for Red Hat Enterprise Linux 8", require world-writable folders to be mounted with the "noexec" option.

The DISA profile is the one that US government agencies would likely use (and which I followed, triggering this bug). But there are many other profiles which probably have the same rule, e.g. NIST (other US government), HIPAA (US healthcare industry), PCI-DSS (US financial / retail / payment card industry), ANSSI (French government), and ACSC (Australian government). So this bug is probably affecting a lot of systems which have certain security requirements.

TBH I have no idea about what all that does. My last pygi commit was 8 years ago, and I didn't work on these core FFI bits.

At first sight, this is too superficial, though -- you can of course try and ignore the ffi_closure_alloc() failure, and see what the tests say (assuming they fail on a system with noexec /tmp/). If they succeed afterwards, great, but that would surprise me -- these closures get created for a reason.

pygobject should of course be more defensive against that, and add a g_return_if_fail() if the ffi allocation fails. But it looks like this needs to be fixed in libffi, so that ffi_closure_alloc() works on such a system?

(In reply to Martin Pitt from comment #14)
> TBH I have no idea about what all that does. My last pygi commit was 8 years
> ago, and I didn't work on these core FFI bits.

Ah, but thank you for your opinion!

> At first sight, this is too superficial, though -- you can of course try and
> ignore the ffi_closure_alloc() failure, and see what the tests say (assuming
> they fail on a system with noexec /tmp/). If they succeed afterwards, great,
> but that would surprise me -- these closures get created for a reason.
> 
> pygobject should of course be more defensive against that, and add a
> g_return_if_fail() if the ffi allocation fails. But it looks like this needs
> to be fixed in libffi, so that ffi_closure_alloc() works on such a system?

Any opinion dj or fweimer?

Hello,

Please note that the fact that libffi cannot execute when all temporary file systems are marked with "nodev" has been fixed through BZ #1875340 (RHEL 8.6.0), so now it's usually expected to run fine.
Still it would be nice to harden the code to not crash on ffi_closure_alloc() failure, who knows, there may be some scenario where this may happen.
We can hence downgrade the priority, but please try fixing this anyway.

(In reply to Tomas Popela from comment #15)
> > pygobject should of course be more defensive against that, and add a
> > g_return_if_fail() if the ffi allocation fails. But it looks like this needs
> > to be fixed in libffi, so that ffi_closure_alloc() works on such a system?
> 
> Any opinion dj or fweimer?

libffi upstream has fixed this by offering a build options for static closures which do not depend at all on run-time code generation anymore. This work is not really backportable. We could maybe fix this with a private libffi version just for use with girepository in Red Hat Enterprise Linux 8.

Issue migration from Bugzilla to Jira is in process at this time. This will be the last message in Jira copied from the Bugzilla bug.

This BZ has been automatically migrated to the issues.redhat.com Red Hat Issue Tracker. All future work related to this report will be managed there.

Due to differences in account names between systems, some fields were not replicated.  Be sure to add yourself to Jira issue's "Watchers" field to continue receiving updates and add others to the "Need Info From" field to continue requesting information.

To find the migrated issue, look in the "Links" section for a direct link to the new issue location. The issue key will have an icon of 2 footprints next to it, and begin with "RHEL-" followed by an integer.  You can also find this issue by visiting https://issues.redhat.com/issues/?jql= and searching the "Bugzilla Bug" field for this BZ's number, e.g. a search like:

"Bugzilla Bug" = 1234567

In the event you have trouble locating or viewing this issue, you can file an issue by sending mail to rh-issues. You can also visit https://access.redhat.com/articles/7032570 for general account information.