Bug 1335986 - BUG: memory allocation failure in inode_doinit_with_dentry()/context_to_sid()
Summary: BUG: memory allocation failure in inode_doinit_with_dentry()/context_to_sid()
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: kernel
Version: 7.2
Hardware: x86_64
OS: Linux
high
high
Target Milestone: rc
: ---
Assignee: Ondrej Mosnacek
QA Contact: Milos Malik
Lenka Špačková
URL:
Whiteboard:
Depends On:
Blocks: 1710468 1760823
TreeView+ depends on / blocked
 
Reported: 2016-05-13 18:16 UTC by Orion Poplawski
Modified: 2019-10-11 12:12 UTC (History)
10 users (show)

Fixed In Version: kernel-3.10.0-1029.el7
Doc Type: Bug Fix
Doc Text:
.An SELinux policy reload no longer causes false ENOMEM Reloading SELinux policy previously caused the internal security context lookup table to become unresponsive. Consequently, when the kernel encountered a new security context during a policy reload, the operation failed with a false "Out of memory" (ENOMEM) error. With this update, the internal Security Identifier (SID) lookup table has been redesigned and no longer freezes. As a result, the kernel no longer returns misleading ENOMEM errors during an SELinux policy reload.
Clone Of:
: 1656787 1710468 1760823 (view as bug list)
Environment:
Last Closed: 2019-08-06 12:05:16 UTC
Target Upstream Version:


Attachments (Terms of Use)


Links
System ID Priority Status Summary Last Updated
Red Hat Product Errata RHSA-2019:2029 None None None 2019-08-06 12:05:42 UTC

Internal Links: 1251577

Description Orion Poplawski 2016-05-13 18:16:47 UTC
Description of problem:

On server boot we run ansible to set configs.  On a boot today we saw:

May 13 05:31:36 mail.nwra.com python[12304]: ansible-<stdin> Invoked with warn=True executable=None _uses_shell=False _raw_params=/usr/sbin/semanage fcontext -a -t httpd_var_lib_t "/var/lib/vacation_sieve(/.*)?" removes=None creates=None chdir=None
May 13 05:31:37 mail.nwra.com kernel: SELinux: 2048 avtab hash slots, 105681 rules.
May 13 05:31:37 mail.nwra.com kernel: SELinux: 2048 avtab hash slots, 105681 rules.
May 13 05:31:37 mail.nwra.com kernel: SELinux:  8 users, 105 roles, 4965 types, 304 bools, 1 sens, 1024 cats
May 13 05:31:37 mail.nwra.com kernel: SELinux:  83 classes, 105681 rules
May 13 05:31:38 mail.nwra.com kernel: SELinux: inode_doinit_with_dentry:  context_to_sid(system_u:object_r:chkpwd_exec_t:s0) returned 12 for dev=md2 ino=1179712


This caused /usr/sbin/unix_chkpwd to end up labeled with unlabeled_t, which broke logins for unix accounts:

May 13 05:31:38 mail.nwra.com sshd[12321]: pam_unix(sshd:account): helper binary execve failed: Permission denied
May 13 05:31:38 mail.nwra.com sshd[12310]: fatal: Access denied for user root by PAM account configuration [preauth]

type=AVC msg=audit(1463147702.138:4501): avc:  denied  { execute } for  pid=15630 comm="sshd" name="unix_chkpwd" dev="md2" ino=1179712 scontext=system_u:system_r:sshd_t:s0-s0:c0.c1023 tcontext=system_u:object_r:unlabeled_t:s0 tclass=file


Version-Release number of selected component (if applicable):
3.10.0-327.18.2.el7.x86_64

How reproducible:
Have not tried yet.

Comment 2 Paul Moore 2016-06-21 15:19:26 UTC
In this case the error code you are seeing (12/ENOMEM) indicates that the kernel was unable to allocate enough memory to properly initialize the file's security label.  Was the system under heavy memory pressure when this occurred?  Have you noticed this on other systems, or was it a one time occurrence?

Comment 3 Orion Poplawski 2016-06-21 15:33:49 UTC
It was during boot, and I would not expect much memory pressure.  Currently the machine reports (which should be typical):

              total        used        free      shared  buff/cache   available
Mem:        7983480     1278868      142128      401236     6562484     5979592
Swap:      16547832      184464    16363368


Looking at logs again I found:

Jun  9 05:44:25 mail python: ansible-<stdin> Invoked with warn=True executable=None _uses_shell=F
alse _raw_params=/usr/sbin/semanage fcontext -a -t httpd_var_lib_t "/var/lib/vacation_sieve(/.*)?" removes=None creates=None chdir=None
Jun  9 05:44:26 mail clamav-milter: ERROR: Failed to initiate streaming/fdpassing
Jun  9 05:44:26 mail clamav-milter: LibClamAV Error: cli_gentempfd: Can't create temporary file /tmp/clamav-3b8174a1a592d17afc580d6ad832cd08.tmp: Cannot allocate memory
Jun  9 05:44:26 mail clamav-milter: ERROR: Failed to create temporary file
Jun  9 05:44:26 mail clamav-milter: ERROR: Failed to initiate streaming/fdpassing
Jun  9 05:44:26 mail kernel: SELinux: inode_doinit_with_dentry:  context_to_sid(system_u:object_r:selinux_login_config_t:s0) returned 12 for dev=md3 ino=1064
Jun  9 05:44:26 mail kernel: SELinux: inode_doinit_with_dentry:  context_to_sid(system_u:object_r:lastlog_t:s0) returned 12 for dev=sda1 ino=4063265
Jun  9 05:44:27 mail dbus-daemon: dbus[789]: avc:  received policyload notice (seqno=2)
Jun  9 05:44:27 mail dbus[789]: avc:  received policyload notice (seqno=2)
Jun  9 05:44:27 mail dbus-daemon: dbus[789]: [system] Reloaded configuration
Jun  9 05:44:27 mail dbus[789]: [system] Reloaded configuration

So perhaps something about ansible or semanage triggers memory pressure.

# ls -ldZ /etc/selinux/targeted/logins
drwxr-xr-x. root root system_u:object_r:unlabeled_t:s0 /etc/selinux/targeted/logins

I remember now fixing the label on lastlog recently, but couldn't figure out what had changed it then.  This must have been it.

# find /var -xdev -inum 4063265
/var/log/lastlog

Comment 4 Paul Moore 2016-06-21 18:39:17 UTC
Can you reliably trigger the problem on boot?

Comment 5 Orion Poplawski 2016-06-21 18:42:06 UTC
I doubt it.  The ansible commands are run at least once a day, and I've only seen it triggered twice so far.

Comment 6 Paul Moore 2016-06-21 19:36:42 UTC
Oh goodie, I do enjoy these sporadic bugs.

I'll keep this BZ open in case we get more reports, or you're able to reproduce it on a more reliable basis, but as it currently stands I'm not sure there is much we can do.  Please keep us current if things change, or get worse.

Comment 7 Orion Poplawski 2016-06-21 19:53:32 UTC
Hmm, I take that back a bit.  The system has been rebooted twice, and each time this error occurred.  So maybe it is reproducible to an extent.  It's our primary (only) company email server so it's not rebooted that often.  I haven't seen it on any other machine.

Any kind of diagnostic information that would be useful to collect the next time I reboot?

Comment 8 Paul Moore 2016-06-21 21:27:06 UTC
Nothing specific to this failure immediately springs to mind, other than what you provided in comment #3.  Although problems like this tend to be very transient and hard to capture/snapshot.

Let me think on this further, but we may be able to do some work to reduce/eliminate the need for the string copies in security_context_to_sid_core() which would help resolve the problem you are seeing.

(NOTE TO FUTURE SELF: this involves changes to string_to_context_struct() and the hash functions)

Comment 9 Paul Moore 2016-09-21 20:20:38 UTC
Hi Orion,

It has been a few months and I just wanted to check on this and see if you are continuing to see this issue?

Comment 10 Orion Poplawski 2016-09-21 20:40:21 UTC
Well, there has only been one reboot since last time (yesterday to get 3.10.0-327.36.1) and that didn't trigger it.  Haven't seen it anywhere else either.  Not much data I'm afraid.

Comment 11 Paul Moore 2017-06-15 18:29:52 UTC
Orion, have you been able to reproduce this at all since last September?

If you are not seeing this problem anymore I'm tempted to close this BZ as there is nothing immediately obvious in the code.

Comment 12 Orion Poplawski 2017-06-16 19:20:56 UTC
Looks like I have one occurrence in the logs I have:

May 18 10:15:54 saga python: ansible-command Invoked with warn=True executable=None _uses_shell=False _raw_params=/usr/sbin/semodule -u /root/ansible-selinux/zabbix_lvs.pp removes=None creates=Nonechdir=None
May 18 10:16:14 saga kernel: SELinux: inode_doinit_with_dentry:  context_to_sid(system_u:object_r:virt_etc_t:s0) returned 12 for dev=dm-3 ino=6377871

Different server but during boot again.  This was with 3.10.0-514.16.1.el7.

Comment 13 Paul Moore 2017-06-16 19:37:50 UTC
Thanks Orion; let's keep this open.

Comment 15 Ondrej Mosnacek 2018-10-05 07:03:49 UTC
Not 100% sure, but this looks like an instance of this bug tracked upstream:

https://github.com/SELinuxProject/selinux-kernel/issues/38

Comment 16 Ondrej Mosnacek 2018-10-08 08:12:10 UTC
Hi Orion,

FYI, I inherited this bug from Paul Moore, who no longer works at RH. I see you Cc'd my private e-mail address (apparently following Paul's advice from the GH discussion), but as you can see I am already subscribed via my work address :)

Anyway, it seems this bug has a simple one-line workaround (see the linked GH issue) so I'll try to come up with a reproducer and see if the workaround works. If we can show that it resolves a real problem then I think it has a good chance to be accepted upstream and then I could backport it.

I would like to eventually overhaul the whole policy reload to fix this properly (along with a bunch of other issues) but that will take some time...

Comment 17 Ondrej Mosnacek 2018-10-08 12:18:07 UTC
I found a simple reproducer via runcon (which calls setexeccon(3)):

while true; do load_policy; echo -n .; sleep 0.1; done &

for (( i = 0; i < 1024; i++ )); do
	runcon -l s0:c$i echo -n x || break
done

(It takes some time to trigger, but if you are patient enough it happens.)

Unfortunately, the EINTR workaround doesn't work out-of-the box for runcon, because it also calls in security_check_context(3), which does not retry on EINTR. This could be fixed in libselinux, but...

Instead of runcon -l <...> one can reproduce this also with chcon -l s0:c$i /some/file, which triggers the bug via setxattr(2). However, setxattr(2) isn't expected to return EINTR (see man pages), so this pretty much foils the whole just-return-EINTR plan :(

Comment 18 Ondrej Mosnacek 2018-11-06 09:37:02 UTC
Hi Orion,

would you mind if I made this BZ publicly accessible? I'm asking because there are some log outputs in description/comments that you might consider sensitive. (There is probably nothing important, but to be on the safe side I rather ask :)

Comment 19 Orion Poplawski 2018-11-06 15:26:25 UTC
Yes, that would be fine.

Comment 20 Ondrej Mosnacek 2018-11-06 15:30:17 UTC
(In reply to Orion Poplawski from comment #19)
> Yes, that would be fine.

Thanks! Let's see if it works...

Comment 26 Bruno Meneguele 2019-03-21 14:04:38 UTC
Patch(es) committed on kernel-3.10.0-1029.el7

Comment 49 errata-xmlrpc 2019-08-06 12:05:16 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHSA-2019:2029


Note You need to log in before you can comment on or make changes to this bug.