Bug 1737812

Summary: optimize closing fds when spawning handlers in PAM by looking up opened handles via /proc/self/fd
Product: Red Hat Enterprise Linux 8 Reporter: Welterlen Benoit <bwelterl>
Component: pamAssignee: Tomas Mraz <tmraz>
Status: CLOSED ERRATA QA Contact: Dalibor Pospíšil <dapospis>
Severity: low Docs Contact:
Priority: low    
Version: 8.2CC: bwelterl, cbesson, dapospis, qe-baseos-security, qguo, rmetrich, tmraz
Target Milestone: rcKeywords: Triaged
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: pam-1.3.1-5.el8 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: 1734723 Environment:
Last Closed: 2020-04-28 16:42:43 UTC Type: Bug
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: 1734723    
Bug Blocks:    
Attachments:
Description Flags
Test tool none

Description Welterlen Benoit 2019-08-06 09:23:02 UTC
+++ This bug was initially created as a clone of Bug #1734723 +++

Description of problem:
pam authentication is slow when nofile limit is high and selinux enabled

Version-Release number of selected component (if applicable):
pam-1.1.8-22.el7.x86_64
1.1.8 Release: 22 RH8

How reproducible:
always

Steps to Reproduce:
1. enable selinux
2. set an high nofile limit
3. authenticate through pam

Full steps:
# cat << EOF >/etc/pam.d/check 
auth       required     pam_unix.so
account    required     pam_unix.so
EOF

# ulimit -n
1024
# ./check_user foo
pam_start 1564501527.672
pam_authenticate 1564501527.675
Password: 
pam_acct_mgmt 1564501530.668
ending 1564501530.671
Authenticated
pam_end 1564501530.671

# echo 5242880 >/proc/sys/fs/nr_open
# ulimit -n 5242880
# ./check_user foo
pam_start 1564501568.525
pam_authenticate 1564501568.527
Password: 
pam_acct_mgmt 1564501572.276
ending 1564501573.235
Authenticated
pam_end 1564501573.235

============================================================================================
check_user.c with timestamp in ms
============================================================================================
#include <security/pam_appl.h>
#include <security/pam_misc.h>
#include <stdio.h>
#include <time.h>
#include <inttypes.h>
#include <math.h>

static struct pam_conv conv = {
    misc_conv,
    NULL
};

void timems(char *str)
{
    long            ms; // Milliseconds
    time_t          s;  // Seconds
    struct timespec spec;

    clock_gettime(CLOCK_REALTIME, &spec);

    s  = spec.tv_sec;
    ms = (int)(spec.tv_nsec / 1.0e6); // Convert nanoseconds to milliseconds
    if (ms > 999) {
        s++;
        ms = 0;
    }

    printf("%s %"PRIdMAX".%03ld\n", str, (intmax_t)s, ms);
}

int main(int argc, char *argv[])
{
    pam_handle_t *pamh=NULL;
    int retval;
    const char *user="foo";

    if(argc == 2) {
	user = argv[1];
    }

    if(argc > 2) {
	fprintf(stderr, "Usage: check_user [username]\n");
	exit(1);
    }

    timems("pam_start");

    retval = pam_start("check", user, &conv, &pamh);

    timems("pam_authenticate");
    if (retval == PAM_SUCCESS)
        retval = pam_authenticate(pamh, 0);    /* is user really user? */

    timems("pam_acct_mgmt");
    if (retval == PAM_SUCCESS)
        retval = pam_acct_mgmt(pamh, 0);       /* permitted access? */

    /* This is where we have been authorized or not. */

    timems("ending");
    if (retval == PAM_SUCCESS) {
	fprintf(stdout, "Authenticated\n");
    } else {
	fprintf(stdout, "Not Authenticated\n");
    }

    timems("pam_end");
    if (pam_end(pamh,retval) != PAM_SUCCESS) {     /* close Linux-PAM */
	pamh = NULL;
	fprintf(stderr, "check_user: failed to release authenticator\n");
	exit(1);
    }

    return ( retval == PAM_SUCCESS ? 0:1 );       /* indicate success */
}

Actual results:
- delay in authentication 

Expected results:
- no delay as without selinux or low nofile limit

Additional info:
The pam stack tries to close a lot of FD, from 1 to the nofile limit (or 1999999).
---
...
Bes16324 16:36:25.964912 close(1008)       = -1 EBADF (Bad file descriptor) <0.000010>
16324 16:36:25.964948 close(1009)       = -1 EBADF (Bad file descriptor) <0.000010>
16324 16:36:25.964984 close(1010)       = -1 EBADF (Bad file descriptor) <0.000011>
16324 16:36:25.965020 close(1011)       = -1 EBADF (Bad file descriptor) <0.000010>
16324 16:36:25.965056 close(1012)       = -1 EBADF (Bad file descriptor) <0.000010>
16324 16:36:25.965091 close(1013)       = -1 EBADF (Bad file descriptor) <0.000010>
16324 16:36:25.965128 close(1014)       = -1 EBADF (Bad file descriptor) <0.000010>
16324 16:36:25.965164 close(1015)       = -1 EBADF (Bad file descriptor) <0.000010>
16324 16:36:25.965199 close(1016)       = -1 EBADF (Bad file descriptor) <0.000010>
...
---

This is not visible without selinux enabled.

The source code responsible of that is here:

modules/pam_unix/pam_unix_passwd.c
8<---------- 8< ---------------- 8< ---------------- 8< -------- #ifdef WITH_SELINUX

static int _unix_run_update_binary(pam_handle_t *pamh, unsigned int ctrl, const char *user,
    const char *fromwhat, const char *towhat, int remember) { ...
        if (getrlimit(RLIMIT_NOFILE,&rlim)==0) {
          if (rlim.rlim_max >= MAX_FD_NO)
            rlim.rlim_max = MAX_FD_NO;
          for (i = STDERR_FILENO + 1; i < (int)rlim.rlim_max; i++) {
            if (i != dummyfds[0])
                close(i);
          }
        }
...
8<---------- 8< ---------------- 8< ---------------- 8< --------

There is a BZ that already describe this kind of issue but only with sudo: [sudo 1.8.23 is significantly slower than 1.8.19p2] https://bugzilla.redhat.com/show_bug.cgi?id=1673906

Comment 1 Welterlen Benoit 2019-08-06 09:40:58 UTC
In upstream code, the close is done in close_fds with MAX_FD_NO = 65535 instead of 2000000:

/* Closes all descriptors after stderr. */
static void
close_fds(void)
{
        /*
         * An arbitrary upper limit for the maximum file descriptor number
         * returned by RLIMIT_NOFILE.
         */
        const int MAX_FD_NO = 65535;

        /* The lower limit is the same as for _POSIX_OPEN_MAX. */
        const int MIN_FD_NO = 20;

        int fd;
        struct rlimit rlim;

        if (getrlimit(RLIMIT_NOFILE, &rlim) || rlim.rlim_max > MAX_FD_NO)
                fd = MAX_FD_NO;
        else if (rlim.rlim_max < MIN_FD_NO)
                fd = MIN_FD_NO;
        else
                fd = rlim.rlim_max - 1;

        for (; fd > STDERR_FILENO; --fd)
                close(fd);
}

In RH7-8, pam 1.1.8:
#define MAX_FD_NO 2000000

Comment 2 Tomas Mraz 2019-08-06 09:51:55 UTC
Actually I've mistakenly thought that the RHEL-8 code is the same as on RHEL-7, but that was already replaced with the close_fds() call. So the problem on RHEL-8 is much much lower than on RHEL-7. But there is still room for optimization if /proc/self/fd is available.

Comment 3 Christophe Besson 2019-08-06 14:48:58 UTC
On RHEL8, this is not a perf issue anymore. With selinux enabled, I got 4 ms with nofile = 4096 or 5M. With the patch below, it take only 2ms.
But for me, using an arbitrary MAX_FD_NO seems to be a bug, so we can try a minor improvement.

###### limits.conf
foo		hard	nofile	5242880
foo		soft	nofile	5242880

###### Without the patch
# ./check_user foo
pam_start 1565099210.112
pam_authenticate 1565099210.116
Password: 
pam_acct_mgmt 1565099212.918
ending 1565099212.922
Authenticated
pam_end 1565099212.922

###### With the patch
# ./check_user foo
pam_start 1565100047.233
pam_authenticate 1565100047.234
Password: 
pam_acct_mgmt 1565100049.152
ending 1565100049.154
Authenticated
pam_end 1565100049.154



/* Closes all descriptors after stderr. */
static void
close_fds(void)
{
        int fd;
        DIR *dir;
        struct dirent *dent;

        if ((dir = opendir("/proc/self/fd")) != NULL) {
                while ((dent = readdir(dir)) != NULL) {
                        if (!strcmp(dent->d_name, ".")
                            || !strcmp(dent->d_name, ".."))
                                continue;
                        fd = atoi(dent->d_name);
                        if (fd > STDERR_FILENO)
                                close(fd);
                }
        }
}


$ cat pam-1.3.1-closefds.patch
diff -up Linux-PAM-1.3.1/libpam/pam_modutil_sanitize.c.cbesson Linux-PAM-1.3.1/libpam/pam_modutil_sanitize.c
--- Linux-PAM-1.3.1/libpam/pam_modutil_sanitize.c.cbesson	2017-02-10 11:10:15.000000000 +0100
+++ Linux-PAM-1.3.1/libpam/pam_modutil_sanitize.c	2019-08-06 15:29:35.000000000 +0200
@@ -10,6 +10,7 @@
 #include <fcntl.h>
 #include <syslog.h>
 #include <sys/resource.h>
+#include <dirent.h>
 
 /*
  * Creates a pipe, closes its write end, redirects fd to its read end.
@@ -116,27 +117,20 @@ redirect_out(pam_handle_t *pamh, enum pa
 static void
 close_fds(void)
 {
-	/*
-	 * An arbitrary upper limit for the maximum file descriptor number
-	 * returned by RLIMIT_NOFILE.
-	 */
-	const int MAX_FD_NO = 65535;
-
-	/* The lower limit is the same as for _POSIX_OPEN_MAX. */
-	const int MIN_FD_NO = 20;
-
 	int fd;
-	struct rlimit rlim;
+	DIR *dir;
+	struct dirent *dent;
 
-	if (getrlimit(RLIMIT_NOFILE, &rlim) || rlim.rlim_max > MAX_FD_NO)
-		fd = MAX_FD_NO;
-	else if (rlim.rlim_max < MIN_FD_NO)
-		fd = MIN_FD_NO;
-	else
-		fd = rlim.rlim_max - 1;
-
-	for (; fd > STDERR_FILENO; --fd)
-		close(fd);
+	if ((dir = opendir("/proc/self/fd")) != NULL) {
+		while ((dent = readdir(dir)) != NULL) {
+			if (!strcmp(dent->d_name, ".")
+			    || !strcmp(dent->d_name, ".."))
+				continue;
+			fd = atoi(dent->d_name);
+			if (fd > STDERR_FILENO)
+				close(fd);
+		}
+	}
 }
 
 int

Comment 4 Tomas Mraz 2019-08-07 08:24:57 UTC
The patch must properly fallback to the previous behavior if opendir fails. Also please submit that as PR on upstream project in GitHub.

Comment 5 Christophe Besson 2019-08-07 10:11:55 UTC
Yep, you're right. Will try to submit that on upstream.


--- libpam/pam_modutil_sanitize.c	2019-08-07 11:36:40.000000000 +0200
+++ libpam/pam_modutil_sanitize.c.new	2019-08-07 12:09:35.000000000 +0200
@@ -10,6 +10,7 @@
 #include <fcntl.h>
 #include <syslog.h>
 #include <sys/resource.h>
+#include <dirent.h>
 
 /*
  * Creates a pipe, closes its write end, redirects fd to its read end.
@@ -116,6 +117,9 @@
 static void
 close_fds(void)
 {
+	DIR *dir;
+	struct dirent *dent;
+
 	/*
 	 * An arbitrary upper limit for the maximum file descriptor number
 	 * returned by RLIMIT_NOFILE.
@@ -128,15 +132,30 @@
 	int fd;
 	struct rlimit rlim;
 
-	if (getrlimit(RLIMIT_NOFILE, &rlim) || rlim.rlim_max > MAX_FD_NO)
-		fd = MAX_FD_NO;
-	else if (rlim.rlim_max < MIN_FD_NO)
-		fd = MIN_FD_NO;
-	else
-		fd = rlim.rlim_max - 1;
-
-	for (; fd > STDERR_FILENO; --fd)
-		close(fd);
+	/* 
+	 * if /proc is mounted, we can optimize what fd can be closed,
+ 	 * but if it isn't available, fall back to the previous behavior.
+	 */
+	if ((dir = opendir("/proc/self/fd")) != NULL) {
+		while ((dent = readdir(dir)) != NULL) {
+			if (!strcmp(dent->d_name, ".")
+			    || !strcmp(dent->d_name, ".."))
+				continue;
+			fd = atoi(dent->d_name);
+			if (fd > STDERR_FILENO)
+				close(fd);
+		}
+	} else {
+		if (getrlimit(RLIMIT_NOFILE, &rlim) || rlim.rlim_max > MAX_FD_NO)
+			fd = MAX_FD_NO;
+		else if (rlim.rlim_max < MIN_FD_NO)
+			fd = MIN_FD_NO;
+		else
+			fd = rlim.rlim_max - 1;
+	
+		for (; fd > STDERR_FILENO; --fd)
+			close(fd);
+	}
 }

Comment 6 Christophe Besson 2019-08-07 12:36:21 UTC
Submitted.

https://github.com/linux-pam/linux-pam/pull/130

Comment 10 Tomas Mraz 2019-12-19 11:15:22 UTC
Created attachment 1646412 [details]
Test tool

This simple tool will perform the authentication.

You will need a pam configuration file /etc/pam.d/tst-pam-unix-closefd with just:
auth required pam_unix.so

If you want the authentication to succeed (not necessary for the test) you also need an user tstpamunix with password pamunix01PSWD

Then just run the test with:
make tst-pam_unix-closefd LDFLAGS='-lpam' CFLAGS='-g -O2 -Wall'
strace -f -o log ./tst-pam_unix-closefd

There should be a line with close(345) in the log and there should not be a line with close(344) in the log.

Comment 11 Tomas Mraz 2019-12-19 11:19:26 UTC
Small correction: The user tstpamunix must be present on the system for the test to work.

Comment 15 errata-xmlrpc 2020-04-28 16:42:43 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/RHBA-2020:1780