2021-05-25 18:30:56

by Scott Mayhew

[permalink] [raw]
Subject: [nfs-utils RFC PATCH 0/2] Two rpc.gssd improvements

These patches provide the following improvements for rpc.gssd:
1) deal with failed thread creation
2) add a timeout for upcall threads

Both of these issues can leave kernel mount processes hanging
indefinitely. A timeout was originally proposed in the kernel
(https://lore.kernel.org/linux-nfs/[email protected]/)
but this approach was rejected by Trond:

I'm saying that we can do this entirely in userland without any kernel
changes. As long as that hasn't been attempted and proven to be flawed,
then there is no reason to accept any kernel patches.

So this is my attempt at doing the timeout in userland.

The first patch was tested using a program that intercepts clone() and
changes the return code to -EAGAIN.

For the second patch, I have two different tests I've been running:

1) In an IPA domain in our lab, I have a server running 100 kerberized
nfsd containers. The client has mountpoints to all 100 of those servers
defined in its /etc/fstab. I run 'systemctl start remote-fs.target' to
kick off all those mounts in parallel, while running the following
systemtap script to periodically mess with the mount processes:

---8<---
global i

probe begin { i=0 }

probe process("/lib64/libgssapi_krb5.so.2").function("gss_acquire_cred")
{
if (++i % 100 == 0) {
printf("delay (i=%d)\n", i)
mdelay(30000)
}
}
---8<---

I actually run the test in a loop... the driver script looks like this:

---8<---
#!/bin/bash
let i=1
while :; do
echo "Round $i"
echo "Mounting"
systemctl start remote-fs.target
echo -n "Waiting on mount.nfs processes to complete "
while pgrep mount.nfs >/dev/null; do
echo -n "."
sleep 1
done
echo -e "\nNumber of nfs4 mounts: $(grep -c nfs4 /proc/mounts)"
echo -e "Unmounting"
umount -a -t nfs4
if ! pgrep gssd >/dev/null; then
echo "gssd is not running - check for crash"
break
fi
echo "Sleeping 5 seconds"
sleep 5
let i=$i+1
done
---8<---

2) In an AD environment in our lab, I added 1000 test users. On a
client machine I have all those users run a script that writes to files
on a NetApp SVM and while that script is running I trigger a LIF
migration on the filer. That forces all those users to establish new
creds with the SVM.

That test looks basically like this
# for i in `seq 1 1000`; do su - testuser$i -c "echo 'PASSWORD'|kinit"; done
# for i in `seq 1 1000`; do su - testuser$i -c "date >/mnt/t/tmp/testuser$i-testfile" & done
# for i in `seq 1 1000`; do su - testuser$i -c test.sh & done

where test.sh is a simple script that writes the date to a file in a
loop:

---8<---
#!/bin/bash
filename=/mnt/t/tmp/$(whoami)-testfile
for i in $(seq 1 300)
do
date >$filename
sleep 1
done
---8<---

While the test users are running the script I run one of the following
commands on the NetApp filer:

network interface migrate -vserver VSERVER -lif LIF -destination-node NODE
network interface revert -vserver VSERVER -lif LIF

-Scott

Scott Mayhew (2):
gssd: deal with failed thread creation
gssd: add timeout for upcall threads

nfs.conf | 2 +
utils/gssd/gssd.c | 202 +++++++++++++++++-----------
utils/gssd/gssd.h | 26 +++-
utils/gssd/gssd.man | 31 ++++-
utils/gssd/gssd_proc.c | 293 ++++++++++++++++++++++++++++++++++-------
5 files changed, 421 insertions(+), 133 deletions(-)

--
2.30.2


2021-05-25 18:30:56

by Scott Mayhew

[permalink] [raw]
Subject: [nfs-utils RFC PATCH 1/2] gssd: deal with failed thread creation

If we fail to create a thread to handle an upcall, we still need to do a
downcall to tell the kernel about the failure, otherwise the process
that is trying to establish gss credentials will hang.

This patch shifts the thread creation down a level in the call chain so
now the main thread does a little more work up front (reading & parsing
the data from the pipefs file) so it has the info it needs to be able
to do the error downcall.

Signed-off-by: Scott Mayhew <[email protected]>
---
utils/gssd/gssd.c | 83 +-----------------
utils/gssd/gssd.h | 11 ++-
utils/gssd/gssd_proc.c | 190 +++++++++++++++++++++++++++++++++--------
3 files changed, 166 insertions(+), 118 deletions(-)

diff --git a/utils/gssd/gssd.c b/utils/gssd/gssd.c
index 1541d371..eb440470 100644
--- a/utils/gssd/gssd.c
+++ b/utils/gssd/gssd.c
@@ -364,7 +364,7 @@ out:
/* Actually frees clp and fields that might be used from other
* threads if was last reference.
*/
-static void
+void
gssd_free_client(struct clnt_info *clp)
{
int refcnt;
@@ -416,55 +416,6 @@ gssd_destroy_client(struct clnt_info *clp)

static void gssd_scan(void);

-static int
-start_upcall_thread(void (*func)(struct clnt_upcall_info *), void *info)
-{
- pthread_attr_t attr;
- pthread_t th;
- int ret;
-
- ret = pthread_attr_init(&attr);
- if (ret != 0) {
- printerr(0, "ERROR: failed to init pthread attr: ret %d: %s\n",
- ret, strerror(errno));
- return ret;
- }
- ret = pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED);
- if (ret != 0) {
- printerr(0, "ERROR: failed to create pthread attr: ret %d: "
- "%s\n", ret, strerror(errno));
- return ret;
- }
-
- ret = pthread_create(&th, &attr, (void *)func, (void *)info);
- if (ret != 0)
- printerr(0, "ERROR: pthread_create failed: ret %d: %s\n",
- ret, strerror(errno));
- return ret;
-}
-
-static struct clnt_upcall_info *alloc_upcall_info(struct clnt_info *clp)
-{
- struct clnt_upcall_info *info;
-
- info = malloc(sizeof(struct clnt_upcall_info));
- if (info == NULL)
- return NULL;
-
- pthread_mutex_lock(&clp_lock);
- clp->refcount++;
- pthread_mutex_unlock(&clp_lock);
- info->clp = clp;
-
- return info;
-}
-
-void free_upcall_info(struct clnt_upcall_info *info)
-{
- gssd_free_client(info->clp);
- free(info);
-}
-
/* For each upcall read the upcall info into the buffer, then create a
* thread in a detached state so that resources are released back into
* the system without the need for a join.
@@ -473,44 +424,16 @@ static void
gssd_clnt_gssd_cb(int UNUSED(fd), short UNUSED(which), void *data)
{
struct clnt_info *clp = data;
- struct clnt_upcall_info *info;
-
- info = alloc_upcall_info(clp);
- if (info == NULL)
- return;

- info->lbuflen = read(clp->gssd_fd, info->lbuf, sizeof(info->lbuf));
- if (info->lbuflen <= 0 || info->lbuf[info->lbuflen-1] != '\n') {
- printerr(0, "WARNING: %s: failed reading request\n", __func__);
- free_upcall_info(info);
- return;
- }
- info->lbuf[info->lbuflen-1] = 0;
-
- if (start_upcall_thread(handle_gssd_upcall, info))
- free_upcall_info(info);
+ handle_gssd_upcall(clp);
}

static void
gssd_clnt_krb5_cb(int UNUSED(fd), short UNUSED(which), void *data)
{
struct clnt_info *clp = data;
- struct clnt_upcall_info *info;
-
- info = alloc_upcall_info(clp);
- if (info == NULL)
- return;
-
- if (read(clp->krb5_fd, &info->uid,
- sizeof(info->uid)) < (ssize_t)sizeof(info->uid)) {
- printerr(0, "WARNING: %s: failed reading uid from krb5 "
- "upcall pipe: %s\n", __func__, strerror(errno));
- free_upcall_info(info);
- return;
- }

- if (start_upcall_thread(handle_krb5_upcall, info))
- free_upcall_info(info);
+ handle_krb5_upcall(clp);
}

static struct clnt_info *
diff --git a/utils/gssd/gssd.h b/utils/gssd/gssd.h
index 1e8c58d4..6d53647e 100644
--- a/utils/gssd/gssd.h
+++ b/utils/gssd/gssd.h
@@ -84,14 +84,17 @@ struct clnt_info {

struct clnt_upcall_info {
struct clnt_info *clp;
- char lbuf[RPC_CHAN_BUF_SIZE];
- int lbuflen;
uid_t uid;
+ int fd;
+ char *srchost;
+ char *target;
+ char *service;
};

-void handle_krb5_upcall(struct clnt_upcall_info *clp);
-void handle_gssd_upcall(struct clnt_upcall_info *clp);
+void handle_krb5_upcall(struct clnt_info *clp);
+void handle_gssd_upcall(struct clnt_info *clp);
void free_upcall_info(struct clnt_upcall_info *info);
+void gssd_free_client(struct clnt_info *clp);


#endif /* _RPC_GSSD_H_ */
diff --git a/utils/gssd/gssd_proc.c b/utils/gssd/gssd_proc.c
index e830f497..ba508b30 100644
--- a/utils/gssd/gssd_proc.c
+++ b/utils/gssd/gssd_proc.c
@@ -80,6 +80,8 @@
#include "nfslib.h"
#include "gss_names.h"

+extern pthread_mutex_t clp_lock;
+
/* Encryption types supported by the kernel rpcsec_gss code */
int num_krb5_enctypes = 0;
krb5_enctype *krb5_enctypes = NULL;
@@ -723,22 +725,135 @@ out_return_error:
goto out;
}

-void
-handle_krb5_upcall(struct clnt_upcall_info *info)
+static struct clnt_upcall_info *
+alloc_upcall_info(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
+ char *target, char *service)
{
- struct clnt_info *clp = info->clp;
+ struct clnt_upcall_info *info;
+
+ info = malloc(sizeof(struct clnt_upcall_info));
+ if (info == NULL)
+ return NULL;
+
+ memset(info, 0, sizeof(*info));
+ pthread_mutex_lock(&clp_lock);
+ clp->refcount++;
+ pthread_mutex_unlock(&clp_lock);
+ info->clp = clp;
+ info->uid = uid;
+ info->fd = fd;
+ if (srchost) {
+ info->srchost = strdup(srchost);
+ if (info->srchost == NULL)
+ goto out_info;
+ }
+ if (target) {
+ info->target = strdup(target);
+ if (info->target == NULL)
+ goto out_srchost;
+ }
+ if (service) {
+ info->service = strdup(service);
+ if (info->service == NULL)
+ goto out_target;
+ }
+
+out:
+ return info;
+
+out_target:
+ if (info->target)
+ free(info->target);
+out_srchost:
+ if (info->srchost)
+ free(info->srchost);
+out_info:
+ free(info);
+ info = NULL;
+ goto out;
+}

- printerr(2, "\n%s: uid %d (%s)\n", __func__, info->uid, clp->relpath);
+void free_upcall_info(struct clnt_upcall_info *info)
+{
+ gssd_free_client(info->clp);
+ if (info->service)
+ free(info->service);
+ if (info->target)
+ free(info->target);
+ if (info->srchost)
+ free(info->srchost);
+ free(info);
+}

- process_krb5_upcall(clp, info->uid, clp->krb5_fd, NULL, NULL, NULL);
+static void
+gssd_work_thread_fn(struct clnt_upcall_info *info)
+{
+ process_krb5_upcall(info->clp, info->uid, info->fd, info->srchost, info->target, info->service);
free_upcall_info(info);
}

+static int
+start_upcall_thread(void (*func)(struct clnt_upcall_info *), void *info)
+{
+ pthread_attr_t attr;
+ pthread_t th;
+ int ret;
+
+ ret = pthread_attr_init(&attr);
+ if (ret != 0) {
+ printerr(0, "ERROR: failed to init pthread attr: ret %d: %s\n",
+ ret, strerror(errno));
+ return ret;
+ }
+ ret = pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED);
+ if (ret != 0) {
+ printerr(0, "ERROR: failed to create pthread attr: ret %d: "
+ "%s\n", ret, strerror(errno));
+ return ret;
+ }
+
+ ret = pthread_create(&th, &attr, (void *)func, (void *)info);
+ if (ret != 0)
+ printerr(0, "ERROR: pthread_create failed: ret %d: %s\n",
+ ret, strerror(errno));
+ else
+ printerr(0, "created thread id 0x%lx\n", th);
+ return ret;
+}
+
+void
+handle_krb5_upcall(struct clnt_info *clp)
+{
+ uid_t uid;
+ struct clnt_upcall_info *info;
+ int err;
+
+ if (read(clp->krb5_fd, &uid, sizeof(uid)) < (ssize_t)sizeof(uid)) {
+ printerr(0, "WARNING: failed reading uid from krb5 "
+ "upcall pipe: %s\n", strerror(errno));
+ return;
+ }
+ printerr(2, "\n%s: uid %d (%s)\n", __func__, uid, clp->relpath);
+
+ info = alloc_upcall_info(clp, uid, clp->krb5_fd, NULL, NULL, NULL);
+ if (info == NULL) {
+ printerr(0, "%s: failed to allocate clnt_upcall_info\n", __func__);
+ do_error_downcall(clp->krb5_fd, uid, -EACCES);
+ return;
+ }
+ err = start_upcall_thread(gssd_work_thread_fn, info);
+ if (err != 0) {
+ do_error_downcall(clp->krb5_fd, uid, -EACCES);
+ free_upcall_info(info);
+ }
+}
+
void
-handle_gssd_upcall(struct clnt_upcall_info *info)
+handle_gssd_upcall(struct clnt_info *clp)
{
- struct clnt_info *clp = info->clp;
uid_t uid;
+ char lbuf[RPC_CHAN_BUF_SIZE];
+ int lbuflen = 0;
char *p;
char *mech = NULL;
char *uidstr = NULL;
@@ -746,20 +861,22 @@ handle_gssd_upcall(struct clnt_upcall_info *info)
char *service = NULL;
char *srchost = NULL;
char *enctypes = NULL;
- char *upcall_str;
- char *pbuf = info->lbuf;
pthread_t tid = pthread_self();
+ struct clnt_upcall_info *info;
+ int err;

- printerr(2, "\n%s(0x%x): '%s' (%s)\n", __func__, tid,
- info->lbuf, clp->relpath);
-
- upcall_str = strdup(info->lbuf);
- if (upcall_str == NULL) {
- printerr(0, "ERROR: malloc failure\n");
- goto out_nomem;
+ lbuflen = read(clp->gssd_fd, lbuf, sizeof(lbuf));
+ if (lbuflen <= 0 || lbuf[lbuflen-1] != '\n') {
+ printerr(0, "WARNING: handle_gssd_upcall: "
+ "failed reading request\n");
+ return;
}
+ lbuf[lbuflen-1] = 0;
+
+ printerr(2, "\n%s(0x%x): '%s' (%s)\n", __func__, tid,
+ lbuf, clp->relpath);

- while ((p = strsep(&pbuf, " "))) {
+ for (p = strtok(lbuf, " "); p; p = strtok(NULL, " ")) {
if (!strncmp(p, "mech=", strlen("mech=")))
mech = p + strlen("mech=");
else if (!strncmp(p, "uid=", strlen("uid=")))
@@ -777,8 +894,8 @@ handle_gssd_upcall(struct clnt_upcall_info *info)
if (!mech || strlen(mech) < 1) {
printerr(0, "WARNING: handle_gssd_upcall: "
"failed to find gss mechanism name "
- "in upcall string '%s'\n", upcall_str);
- goto out;
+ "in upcall string '%s'\n", lbuf);
+ return;
}

if (uidstr) {
@@ -790,21 +907,21 @@ handle_gssd_upcall(struct clnt_upcall_info *info)
if (!uidstr) {
printerr(0, "WARNING: handle_gssd_upcall: "
"failed to find uid "
- "in upcall string '%s'\n", upcall_str);
- goto out;
+ "in upcall string '%s'\n", lbuf);
+ return;
}

if (enctypes && parse_enctypes(enctypes) != 0) {
printerr(0, "WARNING: handle_gssd_upcall: "
"parsing encryption types failed: errno %d\n", errno);
- goto out;
+ return;
}

if (target && strlen(target) < 1) {
printerr(0, "WARNING: handle_gssd_upcall: "
"failed to parse target name "
- "in upcall string '%s'\n", upcall_str);
- goto out;
+ "in upcall string '%s'\n", lbuf);
+ return;
}

/*
@@ -818,21 +935,26 @@ handle_gssd_upcall(struct clnt_upcall_info *info)
if (service && strlen(service) < 1) {
printerr(0, "WARNING: handle_gssd_upcall: "
"failed to parse service type "
- "in upcall string '%s'\n", upcall_str);
- goto out;
+ "in upcall string '%s'\n", lbuf);
+ return;
}

- if (strcmp(mech, "krb5") == 0 && clp->servername)
- process_krb5_upcall(clp, uid, clp->gssd_fd, srchost, target, service);
- else {
+ if (strcmp(mech, "krb5") == 0 && clp->servername) {
+ info = alloc_upcall_info(clp, uid, clp->gssd_fd, srchost, target, service);
+ if (info == NULL) {
+ printerr(0, "%s: failed to allocate clnt_upcall_info\n", __func__);
+ do_error_downcall(clp->gssd_fd, uid, -EACCES);
+ return;
+ }
+ err = start_upcall_thread(gssd_work_thread_fn, info);
+ if (err != 0) {
+ do_error_downcall(clp->gssd_fd, uid, -EACCES);
+ free_upcall_info(info);
+ }
+ } else {
if (clp->servername)
printerr(0, "WARNING: handle_gssd_upcall: "
"received unknown gss mech '%s'\n", mech);
do_error_downcall(clp->gssd_fd, uid, -EACCES);
}
-out:
- free(upcall_str);
-out_nomem:
- free_upcall_info(info);
- return;
}
--
2.30.2

2021-05-25 18:31:47

by Scott Mayhew

[permalink] [raw]
Subject: [nfs-utils RFC PATCH 2/2] gssd: add timeout for upcall threads

Add a global list of active upcalls and a watchdog thread that walks the
list, looking for threads running longer than timeout seconds. By
default, the watchdog thread will cancel these threads and report an
error of -ETIMEDOUT to the kernel. Passing the -C option or setting
cancel-timed-out-upcalls=0 in nfs.conf disables this behavior and
causes the watchdog thread to simply log an error message instead. The
upcall timeout can be specified by passing the -U option or by setting
the upcall-timeout parameter in nfs.conf.

Signed-off-by: Scott Mayhew <[email protected]>
---
nfs.conf | 2 +
utils/gssd/gssd.c | 125 +++++++++++++++++++++++++++++++++++++++-
utils/gssd/gssd.h | 15 +++++
utils/gssd/gssd.man | 31 +++++++++-
utils/gssd/gssd_proc.c | 127 ++++++++++++++++++++++++++++++++---------
5 files changed, 270 insertions(+), 30 deletions(-)

diff --git a/nfs.conf b/nfs.conf
index 31994f61..7a987788 100644
--- a/nfs.conf
+++ b/nfs.conf
@@ -25,6 +25,8 @@
# cred-cache-directory=
# preferred-realm=
# set-home=1
+# upcall-timeout=30
+# cancel-timed-out-upcalls=1
#
[lockd]
# port=0
diff --git a/utils/gssd/gssd.c b/utils/gssd/gssd.c
index eb440470..54a1ea3f 100644
--- a/utils/gssd/gssd.c
+++ b/utils/gssd/gssd.c
@@ -95,9 +95,15 @@ static bool use_gssproxy = false;
pthread_mutex_t clp_lock = PTHREAD_MUTEX_INITIALIZER;
static bool signal_received = false;
static struct event_base *evbase = NULL;
+pthread_mutex_t active_thread_list_lock = PTHREAD_MUTEX_INITIALIZER;
+
+int upcall_timeout = DEF_UPCALL_TIMEOUT;
+static bool cancel_timed_out_upcalls = true;

TAILQ_HEAD(topdir_list_head, topdir) topdir_list;

+TAILQ_HEAD(active_thread_list_head, upcall_thread_info) active_thread_list;
+
struct topdir {
TAILQ_ENTRY(topdir) list;
TAILQ_HEAD(clnt_list_head, clnt_info) clnt_list;
@@ -436,6 +442,100 @@ gssd_clnt_krb5_cb(int UNUSED(fd), short UNUSED(which), void *data)
handle_krb5_upcall(clp);
}

+static int
+scan_active_thread_list(void)
+{
+ struct upcall_thread_info *info;
+ struct timespec now;
+ unsigned int sleeptime;
+ bool sleeptime_set = false;
+ int err;
+ void *tret, *saveprev;
+
+ sleeptime = upcall_timeout;
+ pthread_mutex_lock(&active_thread_list_lock);
+ clock_gettime(CLOCK_MONOTONIC, &now);
+ TAILQ_FOREACH(info, &active_thread_list, list) {
+ err = pthread_tryjoin_np(info->tid, &tret);
+ switch (err) {
+ case 0:
+ if (tret == PTHREAD_CANCELED)
+ printerr(3, "watchdog: thread id 0x%lx cancelled successfully\n",
+ info->tid);
+ saveprev = info->list.tqe_prev;
+ TAILQ_REMOVE(&active_thread_list, info, list);
+ free(info);
+ info = saveprev;
+ break;
+ case EBUSY:
+ if (now.tv_sec >= info->timeout.tv_sec) {
+ if (cancel_timed_out_upcalls && !info->cancelled) {
+ printerr(0, "watchdog: thread id 0x%lx timed out\n",
+ info->tid);
+ pthread_cancel(info->tid);
+ info->cancelled = true;
+ do_error_downcall(info->fd, info->uid, -ETIMEDOUT);
+ } else {
+ printerr(0, "watchdog: thread id 0x%lx running for %ld seconds\n",
+ info->tid,
+ now.tv_sec - info->timeout.tv_sec + upcall_timeout);
+ }
+ } else if (!sleeptime_set) {
+ sleeptime = info->timeout.tv_sec - now.tv_sec;
+ sleeptime_set = true;
+ }
+ break;
+ default:
+ printerr(0, "watchdog: attempt to join thread id 0x%lx returned %d (%s)!\n",
+ info->tid, err, strerror(err));
+ break;
+ }
+ }
+ pthread_mutex_unlock(&active_thread_list_lock);
+
+ return sleeptime;
+}
+
+static void *
+watchdog_thread_fn(void *UNUSED(arg))
+{
+ unsigned int sleeptime;
+
+ for (;;) {
+ sleeptime = scan_active_thread_list();
+ printerr(4, "watchdog: sleeping %u secs\n", sleeptime);
+ sleep(sleeptime);
+ }
+ return (void *)0;
+}
+
+static int
+start_watchdog_thread(void)
+{
+ pthread_attr_t attr;
+ pthread_t th;
+ int ret;
+
+ ret = pthread_attr_init(&attr);
+ if (ret != 0) {
+ printerr(0, "ERROR: failed to init pthread attr: ret %d: %s\n",
+ ret, strerror(errno));
+ return ret;
+ }
+ ret = pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED);
+ if (ret != 0) {
+ printerr(0, "ERROR: failed to create pthread attr: ret %d: %s\n",
+ ret, strerror(errno));
+ return ret;
+ }
+ ret = pthread_create(&th, &attr, watchdog_thread_fn, NULL);
+ if (ret != 0) {
+ printerr(0, "ERROR: pthread_create failed: ret %d: %s\n",
+ ret, strerror(errno));
+ }
+ return ret;
+}
+
static struct clnt_info *
gssd_get_clnt(struct topdir *tdi, const char *name)
{
@@ -825,7 +925,7 @@ sig_die(int signal)
static void
usage(char *progname)
{
- fprintf(stderr, "usage: %s [-f] [-l] [-M] [-n] [-v] [-r] [-p pipefsdir] [-k keytab] [-d ccachedir] [-t timeout] [-R preferred realm] [-D] [-H]\n",
+ fprintf(stderr, "usage: %s [-f] [-l] [-M] [-n] [-v] [-r] [-p pipefsdir] [-k keytab] [-d ccachedir] [-t timeout] [-R preferred realm] [-D] [-H] [-U upcall timeout] [-C]\n",
progname);
exit(1);
}
@@ -846,6 +946,9 @@ read_gss_conf(void)
#endif
context_timeout = conf_get_num("gssd", "context-timeout", context_timeout);
rpc_timeout = conf_get_num("gssd", "rpc-timeout", rpc_timeout);
+ upcall_timeout = conf_get_num("gssd", "upcall-timeout", upcall_timeout);
+ cancel_timed_out_upcalls = conf_get_bool("gssd", "cancel-timed-out-upcalls",
+ cancel_timed_out_upcalls);
s = conf_get_str("gssd", "pipefs-directory");
if (!s)
s = conf_get_str("general", "pipefs-directory");
@@ -887,7 +990,7 @@ main(int argc, char *argv[])
verbosity = conf_get_num("gssd", "verbosity", verbosity);
rpc_verbosity = conf_get_num("gssd", "rpc-verbosity", rpc_verbosity);

- while ((opt = getopt(argc, argv, "HDfvrlmnMp:k:d:t:T:R:")) != -1) {
+ while ((opt = getopt(argc, argv, "HDfvrlmnMp:k:d:t:T:R:U:C")) != -1) {
switch (opt) {
case 'f':
fg = 1;
@@ -938,6 +1041,11 @@ main(int argc, char *argv[])
case 'H':
set_home = false;
break;
+ case 'U':
+ upcall_timeout = atoi(optarg);
+ break;
+ case 'C':
+ cancel_timed_out_upcalls = false;
default:
usage(argv[0]);
break;
@@ -1010,6 +1118,11 @@ main(int argc, char *argv[])
else
progname = argv[0];

+ if (upcall_timeout > MAX_UPCALL_TIMEOUT)
+ upcall_timeout = MAX_UPCALL_TIMEOUT;
+ else if (upcall_timeout < MIN_UPCALL_TIMEOUT)
+ upcall_timeout = MIN_UPCALL_TIMEOUT;
+
initerr(progname, verbosity, fg);
#ifdef HAVE_LIBTIRPC_SET_DEBUG
/*
@@ -1068,6 +1181,14 @@ main(int argc, char *argv[])
}
event_add(inotify_ev, NULL);

+ TAILQ_INIT(&active_thread_list);
+
+ rc = start_watchdog_thread();
+ if (rc != 0) {
+ printerr(0, "ERROR: failed to start watchdog thread: %d\n", rc);
+ exit(EXIT_FAILURE);
+ }
+
TAILQ_INIT(&topdir_list);
gssd_scan();
daemon_ready();
diff --git a/utils/gssd/gssd.h b/utils/gssd/gssd.h
index 6d53647e..ad0d1d93 100644
--- a/utils/gssd/gssd.h
+++ b/utils/gssd/gssd.h
@@ -50,6 +50,11 @@
#define GSSD_DEFAULT_KEYTAB_FILE "/etc/krb5.keytab"
#define GSSD_SERVICE_NAME "nfs"
#define RPC_CHAN_BUF_SIZE 32768
+
+#define MIN_UPCALL_TIMEOUT 5
+#define DEF_UPCALL_TIMEOUT 30
+#define MAX_UPCALL_TIMEOUT 600
+
/*
* The gss mechanisms that we can handle
*/
@@ -91,10 +96,20 @@ struct clnt_upcall_info {
char *service;
};

+struct upcall_thread_info {
+ TAILQ_ENTRY(upcall_thread_info) list;
+ pthread_t tid;
+ struct timespec timeout;
+ uid_t uid;
+ int fd;
+ bool cancelled;
+};
+
void handle_krb5_upcall(struct clnt_info *clp);
void handle_gssd_upcall(struct clnt_info *clp);
void free_upcall_info(struct clnt_upcall_info *info);
void gssd_free_client(struct clnt_info *clp);
+int do_error_downcall(int k5_fd, uid_t uid, int err);


#endif /* _RPC_GSSD_H_ */
diff --git a/utils/gssd/gssd.man b/utils/gssd/gssd.man
index 9ae6def9..20fea729 100644
--- a/utils/gssd/gssd.man
+++ b/utils/gssd/gssd.man
@@ -8,7 +8,7 @@
rpc.gssd \- RPCSEC_GSS daemon
.SH SYNOPSIS
.B rpc.gssd
-.RB [ \-DfMnlvrH ]
+.RB [ \-DfMnlvrHC ]
.RB [ \-k
.IR keytab ]
.RB [ \-p
@@ -17,6 +17,10 @@ rpc.gssd \- RPCSEC_GSS daemon
.IR ccachedir ]
.RB [ \-t
.IR timeout ]
+.RB [ \-T
+.IR timeout ]
+.RB [ \-U
+.IR timeout ]
.RB [ \-R
.IR realm ]
.SH INTRODUCTION
@@ -275,7 +279,7 @@ seconds, which allows changing Kerberos tickets and identities frequently.
The default is no explicit timeout, which means the kernel context will live
the lifetime of the Kerberos service ticket used in its creation.
.TP
-.B -T timeout
+.BI "-T " timeout
Timeout, in seconds, to create an RPC connection with a server while
establishing an authenticated gss context for a user.
The default timeout is set to 5 seconds.
@@ -283,6 +287,18 @@ If you get messages like "WARNING: can't create tcp rpc_clnt to server
%servername% for user with uid %uid%: RPC: Remote system error -
Connection timed out", you should consider an increase of this timeout.
.TP
+.BI "-U " timeout
+Timeout, in seconds, for upcall threads. Threads executing longer than
+.I timeout
+seconds will be cancelled and an error of -ETIMEDOUT will be reported
+to the kernel. The default
+.I timeout
+is 30 seconds. The minimum is 5 seconds. The maximum is 600 seconds.
+.TP
+.B -C
+Instead of cancelling upcall threads that have timed out, cause an error
+message to be logged to the syslog (no error will be reported to the kernel).
+.TP
.B -H
Avoids setting $HOME to "/". This allows rpc.gssd to read per user k5identity
files versus trying to read /.k5identity for each user.
@@ -350,6 +366,17 @@ Equivalent to
Equivalent to
.BR -R .
.TP
+.B upcall-timeout
+Equivalent to
+.BR -U .
+.TP
+.B cancel-timed-out-upcalls
+Setting to
+.B false
+is equivalent to providing the
+.B -C
+flag.
+.TP
.B set-home
Setting to
.B false
diff --git a/utils/gssd/gssd_proc.c b/utils/gssd/gssd_proc.c
index ba508b30..ac7b1d1c 100644
--- a/utils/gssd/gssd_proc.c
+++ b/utils/gssd/gssd_proc.c
@@ -81,11 +81,23 @@
#include "gss_names.h"

extern pthread_mutex_t clp_lock;
+extern pthread_mutex_t active_thread_list_lock;
+extern int upcall_timeout;
+extern TAILQ_HEAD(active_thread_list_head, upcall_thread_info) active_thread_list;

/* Encryption types supported by the kernel rpcsec_gss code */
int num_krb5_enctypes = 0;
krb5_enctype *krb5_enctypes = NULL;

+struct cleanup_args {
+ OM_uint32 *min_stat;
+ gss_buffer_t acceptor;
+ gss_buffer_t token;
+ struct authgss_private_data *pd;
+ AUTH **auth;
+ CLIENT **rpc_clnt;
+};
+
/*
* Parse the supported encryption type information
*/
@@ -184,7 +196,7 @@ out_err:
return;
}

-static int
+int
do_error_downcall(int k5_fd, uid_t uid, int err)
{
char buf[1024];
@@ -607,14 +619,37 @@ out:
return auth;
}

+static void
+cleanup_handler(void *arg)
+{
+ struct cleanup_args *args = (struct cleanup_args *)arg;
+
+ gss_release_buffer(args->min_stat, args->acceptor);
+ if (args->token->value)
+ free(args->token->value);
+#ifdef HAVE_AUTHGSS_FREE_PRIVATE_DATA
+ if (args->pd->pd_ctx_hndl.length != 0 || args->pd->pd_ctx != 0)
+ authgss_free_private_data(args->pd);
+#endif
+ if (*args->auth)
+ AUTH_DESTROY(*args->auth);
+ if (*args->rpc_clnt)
+ clnt_destroy(*args->rpc_clnt);
+}
+
/*
* this code uses the userland rpcsec gss library to create a krb5
* context on behalf of the kernel
*/
static void
-process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
- char *tgtname, char *service)
+process_krb5_upcall(struct clnt_upcall_info *info)
{
+ struct clnt_info *clp = info->clp;
+ uid_t uid = info->uid;
+ int fd = info->fd;
+ char *srchost = info->srchost;
+ char *tgtname = info->target;
+ char *service = info->service;
CLIENT *rpc_clnt = NULL;
AUTH *auth = NULL;
struct authgss_private_data pd;
@@ -624,11 +659,13 @@ process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
gss_name_t gacceptor = GSS_C_NO_NAME;
gss_OID mech;
gss_buffer_desc acceptor = {0};
+ struct cleanup_args cleanup_args = {&min_stat, &acceptor, &token, &pd, &auth, &rpc_clnt};

token.length = 0;
token.value = NULL;
memset(&pd, 0, sizeof(struct authgss_private_data));

+ pthread_cleanup_push(cleanup_handler, &cleanup_args);
/*
* If "service" is specified, then the kernel is indicating that
* we must use machine credentials for this request. (Regardless
@@ -650,6 +687,7 @@ process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
* used for this case is not important.
*
*/
+ pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);
if (uid != 0 || (uid == 0 && root_uses_machine_creds == 0 &&
service == NULL)) {

@@ -670,15 +708,21 @@ process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
goto out_return_error;
}
}
+ pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
+ pthread_testcancel();

+ pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);
if (!authgss_get_private_data(auth, &pd)) {
printerr(1, "WARNING: Failed to obtain authentication "
"data for user with uid %d for server %s\n",
uid, clp->servername);
goto out_return_error;
}
+ pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
+ pthread_testcancel();

/* Grab the context lifetime and acceptor name out of the ctx. */
+ pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);
maj_stat = gss_inquire_context(&min_stat, pd.pd_ctx, NULL, &gacceptor,
&lifetime_rec, &mech, NULL, NULL, NULL);

@@ -690,37 +734,35 @@ process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
get_hostbased_client_buffer(gacceptor, mech, &acceptor);
gss_release_name(&min_stat, &gacceptor);
}
+ pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
+ pthread_testcancel();

/*
* The serialization can mean turning pd.pd_ctx into a lucid context. If
* that happens then the pd.pd_ctx will be unusable, so we must never
* try to use it after this point.
*/
+ pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);
if (serialize_context_for_kernel(&pd.pd_ctx, &token, &krb5oid, NULL)) {
printerr(1, "WARNING: Failed to serialize krb5 context for "
"user with uid %d for server %s\n",
uid, clp->servername);
goto out_return_error;
}
+ pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
+ pthread_testcancel();

do_downcall(fd, uid, &pd, &token, lifetime_rec, &acceptor);

out:
- gss_release_buffer(&min_stat, &acceptor);
- if (token.value)
- free(token.value);
-#ifdef HAVE_AUTHGSS_FREE_PRIVATE_DATA
- if (pd.pd_ctx_hndl.length != 0 || pd.pd_ctx != 0)
- authgss_free_private_data(&pd);
-#endif
- if (auth)
- AUTH_DESTROY(auth);
- if (rpc_clnt)
- clnt_destroy(rpc_clnt);
+ pthread_cleanup_pop(1);

return;

out_return_error:
+ pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
+ pthread_testcancel();
+
do_error_downcall(fd, uid, downcall_err);
goto out;
}
@@ -786,38 +828,71 @@ void free_upcall_info(struct clnt_upcall_info *info)
}

static void
-gssd_work_thread_fn(struct clnt_upcall_info *info)
+cleanup_clnt_upcall_info(void *arg)
{
- process_krb5_upcall(info->clp, info->uid, info->fd, info->srchost, info->target, info->service);
+ struct clnt_upcall_info *info = (struct clnt_upcall_info *)arg;
+
free_upcall_info(info);
}

+static void
+gssd_work_thread_fn(struct clnt_upcall_info *info)
+{
+ pthread_cleanup_push(cleanup_clnt_upcall_info, info);
+ process_krb5_upcall(info);
+ pthread_cleanup_pop(1);
+}
+
+static struct upcall_thread_info *
+alloc_upcall_thread_info(void)
+{
+ struct upcall_thread_info *info;
+
+ info = malloc(sizeof(struct upcall_thread_info));
+ if (info == NULL)
+ return NULL;
+ memset(info, 0, sizeof(*info));
+ return info;
+}
+
static int
-start_upcall_thread(void (*func)(struct clnt_upcall_info *), void *info)
+start_upcall_thread(void (*func)(struct clnt_upcall_info *), struct clnt_upcall_info *info)
{
pthread_attr_t attr;
pthread_t th;
+ struct upcall_thread_info *tinfo;
int ret;

+ tinfo = alloc_upcall_thread_info();
+ if (!tinfo)
+ return -ENOMEM;
+ tinfo->fd = info->fd;
+ tinfo->uid = info->uid;
+ tinfo->cancelled = false;
+
ret = pthread_attr_init(&attr);
if (ret != 0) {
printerr(0, "ERROR: failed to init pthread attr: ret %d: %s\n",
ret, strerror(errno));
- return ret;
- }
- ret = pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED);
- if (ret != 0) {
- printerr(0, "ERROR: failed to create pthread attr: ret %d: "
- "%s\n", ret, strerror(errno));
+ free(tinfo);
return ret;
}

ret = pthread_create(&th, &attr, (void *)func, (void *)info);
- if (ret != 0)
+ if (ret != 0) {
printerr(0, "ERROR: pthread_create failed: ret %d: %s\n",
ret, strerror(errno));
- else
- printerr(0, "created thread id 0x%lx\n", th);
+ free(tinfo);
+ return ret;
+ }
+ printerr(1, "created thread id 0x%lx\n", th);
+ tinfo->tid = th;
+ pthread_mutex_lock(&active_thread_list_lock);
+ clock_gettime(CLOCK_MONOTONIC, &tinfo->timeout);
+ tinfo->timeout.tv_sec += upcall_timeout;
+ TAILQ_INSERT_TAIL(&active_thread_list, tinfo, list);
+ pthread_mutex_unlock(&active_thread_list_lock);
+
return ret;
}

--
2.30.2

2021-05-25 19:14:17

by Steve Dickson

[permalink] [raw]
Subject: Re: [nfs-utils RFC PATCH 1/2] gssd: deal with failed thread creation

Hey!

Just a couple of nits...

On 5/25/21 2:00 PM, Scott Mayhew wrote:
> If we fail to create a thread to handle an upcall, we still need to do a
> downcall to tell the kernel about the failure, otherwise the process
> that is trying to establish gss credentials will hang.
>
> This patch shifts the thread creation down a level in the call chain so
> now the main thread does a little more work up front (reading & parsing
> the data from the pipefs file) so it has the info it needs to be able
> to do the error downcall.
>
> Signed-off-by: Scott Mayhew <[email protected]>
> ---
> utils/gssd/gssd.c | 83 +-----------------
> utils/gssd/gssd.h | 11 ++-
> utils/gssd/gssd_proc.c | 190 +++++++++++++++++++++++++++++++++--------
> 3 files changed, 166 insertions(+), 118 deletions(-)
>
> diff --git a/utils/gssd/gssd.c b/utils/gssd/gssd.c
> index 1541d371..eb440470 100644
> --- a/utils/gssd/gssd.c
> +++ b/utils/gssd/gssd.c
> @@ -364,7 +364,7 @@ out:
> /* Actually frees clp and fields that might be used from other
> * threads if was last reference.
> */
> -static void
> +void
> gssd_free_client(struct clnt_info *clp)
> {
> int refcnt;
> @@ -416,55 +416,6 @@ gssd_destroy_client(struct clnt_info *clp)
>
> static void gssd_scan(void);
>
> -static int
> -start_upcall_thread(void (*func)(struct clnt_upcall_info *), void *info)
> -{
> - pthread_attr_t attr;
> - pthread_t th;
> - int ret;
> -
> - ret = pthread_attr_init(&attr);
> - if (ret != 0) {
> - printerr(0, "ERROR: failed to init pthread attr: ret %d: %s\n",
> - ret, strerror(errno));
> - return ret;
> - }
> - ret = pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED);
> - if (ret != 0) {
> - printerr(0, "ERROR: failed to create pthread attr: ret %d: "
> - "%s\n", ret, strerror(errno));
> - return ret;
> - }
> -
> - ret = pthread_create(&th, &attr, (void *)func, (void *)info);
> - if (ret != 0)
> - printerr(0, "ERROR: pthread_create failed: ret %d: %s\n",
> - ret, strerror(errno));
> - return ret;
> -}
> -
> -static struct clnt_upcall_info *alloc_upcall_info(struct clnt_info *clp)
> -{
> - struct clnt_upcall_info *info;
> -
> - info = malloc(sizeof(struct clnt_upcall_info));
> - if (info == NULL)
> - return NULL;
> -
> - pthread_mutex_lock(&clp_lock);
> - clp->refcount++;
> - pthread_mutex_unlock(&clp_lock);
> - info->clp = clp;
> -
> - return info;
> -}
> -
> -void free_upcall_info(struct clnt_upcall_info *info)
> -{
> - gssd_free_client(info->clp);
> - free(info);
> -}
> -
> /* For each upcall read the upcall info into the buffer, then create a
> * thread in a detached state so that resources are released back into
> * the system without the need for a join.
> @@ -473,44 +424,16 @@ static void
> gssd_clnt_gssd_cb(int UNUSED(fd), short UNUSED(which), void *data)
> {
> struct clnt_info *clp = data;
> - struct clnt_upcall_info *info;
> -
> - info = alloc_upcall_info(clp);
> - if (info == NULL)
> - return;
>
> - info->lbuflen = read(clp->gssd_fd, info->lbuf, sizeof(info->lbuf));
> - if (info->lbuflen <= 0 || info->lbuf[info->lbuflen-1] != '\n') {
> - printerr(0, "WARNING: %s: failed reading request\n", __func__);
> - free_upcall_info(info);
> - return;
> - }
> - info->lbuf[info->lbuflen-1] = 0;
> -
> - if (start_upcall_thread(handle_gssd_upcall, info))
> - free_upcall_info(info);
> + handle_gssd_upcall(clp);
> }
>
> static void
> gssd_clnt_krb5_cb(int UNUSED(fd), short UNUSED(which), void *data)
> {
> struct clnt_info *clp = data;
> - struct clnt_upcall_info *info;
> -
> - info = alloc_upcall_info(clp);
> - if (info == NULL)
> - return;
> -
> - if (read(clp->krb5_fd, &info->uid,
> - sizeof(info->uid)) < (ssize_t)sizeof(info->uid)) {
> - printerr(0, "WARNING: %s: failed reading uid from krb5 "
> - "upcall pipe: %s\n", __func__, strerror(errno));
> - free_upcall_info(info);
> - return;
> - }
>
> - if (start_upcall_thread(handle_krb5_upcall, info))
> - free_upcall_info(info);
> + handle_krb5_upcall(clp);
> }
>
> static struct clnt_info *
> diff --git a/utils/gssd/gssd.h b/utils/gssd/gssd.h
> index 1e8c58d4..6d53647e 100644
> --- a/utils/gssd/gssd.h
> +++ b/utils/gssd/gssd.h
> @@ -84,14 +84,17 @@ struct clnt_info {
>
> struct clnt_upcall_info {
> struct clnt_info *clp;
> - char lbuf[RPC_CHAN_BUF_SIZE];
> - int lbuflen;
> uid_t uid;
> + int fd;
> + char *srchost;
> + char *target;
> + char *service;
> };
>
> -void handle_krb5_upcall(struct clnt_upcall_info *clp);
> -void handle_gssd_upcall(struct clnt_upcall_info *clp);
> +void handle_krb5_upcall(struct clnt_info *clp);
> +void handle_gssd_upcall(struct clnt_info *clp);
> void free_upcall_info(struct clnt_upcall_info *info);
> +void gssd_free_client(struct clnt_info *clp);
>
>
> #endif /* _RPC_GSSD_H_ */
> diff --git a/utils/gssd/gssd_proc.c b/utils/gssd/gssd_proc.c
> index e830f497..ba508b30 100644
> --- a/utils/gssd/gssd_proc.c
> +++ b/utils/gssd/gssd_proc.c
> @@ -80,6 +80,8 @@
> #include "nfslib.h"
> #include "gss_names.h"
>
> +extern pthread_mutex_t clp_lock;
> +
> /* Encryption types supported by the kernel rpcsec_gss code */
> int num_krb5_enctypes = 0;
> krb5_enctype *krb5_enctypes = NULL;
> @@ -723,22 +725,135 @@ out_return_error:
> goto out;
> }
>
> -void
> -handle_krb5_upcall(struct clnt_upcall_info *info)
> +static struct clnt_upcall_info *
> +alloc_upcall_info(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
> + char *target, char *service)
> {
> - struct clnt_info *clp = info->clp;
> + struct clnt_upcall_info *info;
> +
> + info = malloc(sizeof(struct clnt_upcall_info));
> + if (info == NULL)
> + return NULL;
> +
> + memset(info, 0, sizeof(*info));
> + pthread_mutex_lock(&clp_lock);
> + clp->refcount++;
> + pthread_mutex_unlock(&clp_lock);
> + info->clp = clp;
> + info->uid = uid;
> + info->fd = fd;
> + if (srchost) {
> + info->srchost = strdup(srchost);
> + if (info->srchost == NULL)
> + goto out_info;
> + }
> + if (target) {
> + info->target = strdup(target);
> + if (info->target == NULL)
> + goto out_srchost;
> + }
> + if (service) {
> + info->service = strdup(service);
> + if (info->service == NULL)
> + goto out_target;
> + }
> +
> +out:
> + return info;
> +
> +out_target:
> + if (info->target)
> + free(info->target);
> +out_srchost:
> + if (info->srchost)
> + free(info->srchost);
> +out_info:
> + free(info);
> + info = NULL;
> + goto out;
> +}
>
> - printerr(2, "\n%s: uid %d (%s)\n", __func__, info->uid, clp->relpath);
> +void free_upcall_info(struct clnt_upcall_info *info)
> +{
> + gssd_free_client(info->clp);
> + if (info->service)
> + free(info->service);
> + if (info->target)
> + free(info->target);
> + if (info->srchost)
> + free(info->srchost);
> + free(info);
> +}
>
> - process_krb5_upcall(clp, info->uid, clp->krb5_fd, NULL, NULL, NULL);
> +static void
> +gssd_work_thread_fn(struct clnt_upcall_info *info)
> +{
> + process_krb5_upcall(info->clp, info->uid, info->fd, info->srchost, info->target, info->service);
> free_upcall_info(info);
> }
>
> +static int
> +start_upcall_thread(void (*func)(struct clnt_upcall_info *), void *info)
> +{
> + pthread_attr_t attr;
> + pthread_t th;
> + int ret;
> +
> + ret = pthread_attr_init(&attr);
> + if (ret != 0) {
> + printerr(0, "ERROR: failed to init pthread attr: ret %d: %s\n",
> + ret, strerror(errno));
> + return ret;
> + }
> + ret = pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED);
> + if (ret != 0) {
> + printerr(0, "ERROR: failed to create pthread attr: ret %d: "
> + "%s\n", ret, strerror(errno));
> + return ret;
> + }
> +
> + ret = pthread_create(&th, &attr, (void *)func, (void *)info);
> + if (ret != 0)
> + printerr(0, "ERROR: pthread_create failed: ret %d: %s\n",
> + ret, strerror(errno));
> + else
> + printerr(0, "created thread id 0x%lx\n", th);
printerr(0) are used for errors not debugging... But I'm wondering
if this debug statement is even needed... Since we tids are not
included in other debugging statements, how would they info be useful?


> + return ret;
> +}
> +
> +void
> +handle_krb5_upcall(struct clnt_info *clp)
> +{
> + uid_t uid;
> + struct clnt_upcall_info *info;
> + int err;
> +
> + if (read(clp->krb5_fd, &uid, sizeof(uid)) < (ssize_t)sizeof(uid)) {
> + printerr(0, "WARNING: failed reading uid from krb5 "
> + "upcall pipe: %s\n", strerror(errno));
> + return;
> + }
> + printerr(2, "\n%s: uid %d (%s)\n", __func__, uid, clp->relpath);
> +
> + info = alloc_upcall_info(clp, uid, clp->krb5_fd, NULL, NULL, NULL);
> + if (info == NULL) {
> + printerr(0, "%s: failed to allocate clnt_upcall_info\n", __func__);
> + do_error_downcall(clp->krb5_fd, uid, -EACCES);
> + return;
> + }
> + err = start_upcall_thread(gssd_work_thread_fn, info);
> + if (err != 0) {
> + do_error_downcall(clp->krb5_fd, uid, -EACCES);
> + free_upcall_info(info);
> + }
> +}
Why is -EACCES being used in both failures? Shouldn't errno be used
or at least ENOMEM for the alloc_upcall_info() failure?

Again... these are just nits.. so a repost is not necessary
Just wanted to get your thoughts on them.

steved.

> +
> void
> -handle_gssd_upcall(struct clnt_upcall_info *info)
> +handle_gssd_upcall(struct clnt_info *clp)
> {
> - struct clnt_info *clp = info->clp;
> uid_t uid;
> + char lbuf[RPC_CHAN_BUF_SIZE];
> + int lbuflen = 0;
> char *p;
> char *mech = NULL;
> char *uidstr = NULL;
> @@ -746,20 +861,22 @@ handle_gssd_upcall(struct clnt_upcall_info *info)
> char *service = NULL;
> char *srchost = NULL;
> char *enctypes = NULL;
> - char *upcall_str;
> - char *pbuf = info->lbuf;
> pthread_t tid = pthread_self();
> + struct clnt_upcall_info *info;
> + int err;
>
> - printerr(2, "\n%s(0x%x): '%s' (%s)\n", __func__, tid,
> - info->lbuf, clp->relpath);
> -
> - upcall_str = strdup(info->lbuf);
> - if (upcall_str == NULL) {
> - printerr(0, "ERROR: malloc failure\n");
> - goto out_nomem;
> + lbuflen = read(clp->gssd_fd, lbuf, sizeof(lbuf));
> + if (lbuflen <= 0 || lbuf[lbuflen-1] != '\n') {
> + printerr(0, "WARNING: handle_gssd_upcall: "
> + "failed reading request\n");
> + return;
> }
> + lbuf[lbuflen-1] = 0;
> +
> + printerr(2, "\n%s(0x%x): '%s' (%s)\n", __func__, tid,
> + lbuf, clp->relpath);
>
> - while ((p = strsep(&pbuf, " "))) {
> + for (p = strtok(lbuf, " "); p; p = strtok(NULL, " ")) {
> if (!strncmp(p, "mech=", strlen("mech=")))
> mech = p + strlen("mech=");
> else if (!strncmp(p, "uid=", strlen("uid=")))
> @@ -777,8 +894,8 @@ handle_gssd_upcall(struct clnt_upcall_info *info)
> if (!mech || strlen(mech) < 1) {
> printerr(0, "WARNING: handle_gssd_upcall: "
> "failed to find gss mechanism name "
> - "in upcall string '%s'\n", upcall_str);
> - goto out;
> + "in upcall string '%s'\n", lbuf);
> + return;
> }
>
> if (uidstr) {
> @@ -790,21 +907,21 @@ handle_gssd_upcall(struct clnt_upcall_info *info)
> if (!uidstr) {
> printerr(0, "WARNING: handle_gssd_upcall: "
> "failed to find uid "
> - "in upcall string '%s'\n", upcall_str);
> - goto out;
> + "in upcall string '%s'\n", lbuf);
> + return;
> }
>
> if (enctypes && parse_enctypes(enctypes) != 0) {
> printerr(0, "WARNING: handle_gssd_upcall: "
> "parsing encryption types failed: errno %d\n", errno);
> - goto out;
> + return;
> }
>
> if (target && strlen(target) < 1) {
> printerr(0, "WARNING: handle_gssd_upcall: "
> "failed to parse target name "
> - "in upcall string '%s'\n", upcall_str);
> - goto out;
> + "in upcall string '%s'\n", lbuf);
> + return;
> }
>
> /*
> @@ -818,21 +935,26 @@ handle_gssd_upcall(struct clnt_upcall_info *info)
> if (service && strlen(service) < 1) {
> printerr(0, "WARNING: handle_gssd_upcall: "
> "failed to parse service type "
> - "in upcall string '%s'\n", upcall_str);
> - goto out;
> + "in upcall string '%s'\n", lbuf);
> + return;
> }
>
> - if (strcmp(mech, "krb5") == 0 && clp->servername)
> - process_krb5_upcall(clp, uid, clp->gssd_fd, srchost, target, service);
> - else {
> + if (strcmp(mech, "krb5") == 0 && clp->servername) {
> + info = alloc_upcall_info(clp, uid, clp->gssd_fd, srchost, target, service);
> + if (info == NULL) {
> + printerr(0, "%s: failed to allocate clnt_upcall_info\n", __func__);
> + do_error_downcall(clp->gssd_fd, uid, -EACCES);
> + return;
> + }
> + err = start_upcall_thread(gssd_work_thread_fn, info);
> + if (err != 0) {
> + do_error_downcall(clp->gssd_fd, uid, -EACCES);
> + free_upcall_info(info);
> + }
> + } else {
> if (clp->servername)
> printerr(0, "WARNING: handle_gssd_upcall: "
> "received unknown gss mech '%s'\n", mech);
> do_error_downcall(clp->gssd_fd, uid, -EACCES);
> }
> -out:
> - free(upcall_str);
> -out_nomem:
> - free_upcall_info(info);
> - return;
> }
>

2021-05-25 22:32:01

by Scott Mayhew

[permalink] [raw]
Subject: Re: [nfs-utils RFC PATCH 1/2] gssd: deal with failed thread creation

On Tue, 25 May 2021, Steve Dickson wrote:

> Hey!
>
> Just a couple of nits...
>
> On 5/25/21 2:00 PM, Scott Mayhew wrote:
> > If we fail to create a thread to handle an upcall, we still need to do a
> > downcall to tell the kernel about the failure, otherwise the process
> > that is trying to establish gss credentials will hang.
> >
> > This patch shifts the thread creation down a level in the call chain so
> > now the main thread does a little more work up front (reading & parsing
> > the data from the pipefs file) so it has the info it needs to be able
> > to do the error downcall.
> >
> > Signed-off-by: Scott Mayhew <[email protected]>
> > ---
> > utils/gssd/gssd.c | 83 +-----------------
> > utils/gssd/gssd.h | 11 ++-
> > utils/gssd/gssd_proc.c | 190 +++++++++++++++++++++++++++++++++--------
> > 3 files changed, 166 insertions(+), 118 deletions(-)
> >
> > diff --git a/utils/gssd/gssd.c b/utils/gssd/gssd.c
> > index 1541d371..eb440470 100644
> > --- a/utils/gssd/gssd.c
> > +++ b/utils/gssd/gssd.c
> > @@ -364,7 +364,7 @@ out:
> > /* Actually frees clp and fields that might be used from other
> > * threads if was last reference.
> > */
> > -static void
> > +void
> > gssd_free_client(struct clnt_info *clp)
> > {
> > int refcnt;
> > @@ -416,55 +416,6 @@ gssd_destroy_client(struct clnt_info *clp)
> >
> > static void gssd_scan(void);
> >
> > -static int
> > -start_upcall_thread(void (*func)(struct clnt_upcall_info *), void *info)
> > -{
> > - pthread_attr_t attr;
> > - pthread_t th;
> > - int ret;
> > -
> > - ret = pthread_attr_init(&attr);
> > - if (ret != 0) {
> > - printerr(0, "ERROR: failed to init pthread attr: ret %d: %s\n",
> > - ret, strerror(errno));
> > - return ret;
> > - }
> > - ret = pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED);
> > - if (ret != 0) {
> > - printerr(0, "ERROR: failed to create pthread attr: ret %d: "
> > - "%s\n", ret, strerror(errno));
> > - return ret;
> > - }
> > -
> > - ret = pthread_create(&th, &attr, (void *)func, (void *)info);
> > - if (ret != 0)
> > - printerr(0, "ERROR: pthread_create failed: ret %d: %s\n",
> > - ret, strerror(errno));
> > - return ret;
> > -}
> > -
> > -static struct clnt_upcall_info *alloc_upcall_info(struct clnt_info *clp)
> > -{
> > - struct clnt_upcall_info *info;
> > -
> > - info = malloc(sizeof(struct clnt_upcall_info));
> > - if (info == NULL)
> > - return NULL;
> > -
> > - pthread_mutex_lock(&clp_lock);
> > - clp->refcount++;
> > - pthread_mutex_unlock(&clp_lock);
> > - info->clp = clp;
> > -
> > - return info;
> > -}
> > -
> > -void free_upcall_info(struct clnt_upcall_info *info)
> > -{
> > - gssd_free_client(info->clp);
> > - free(info);
> > -}
> > -
> > /* For each upcall read the upcall info into the buffer, then create a
> > * thread in a detached state so that resources are released back into
> > * the system without the need for a join.
> > @@ -473,44 +424,16 @@ static void
> > gssd_clnt_gssd_cb(int UNUSED(fd), short UNUSED(which), void *data)
> > {
> > struct clnt_info *clp = data;
> > - struct clnt_upcall_info *info;
> > -
> > - info = alloc_upcall_info(clp);
> > - if (info == NULL)
> > - return;
> >
> > - info->lbuflen = read(clp->gssd_fd, info->lbuf, sizeof(info->lbuf));
> > - if (info->lbuflen <= 0 || info->lbuf[info->lbuflen-1] != '\n') {
> > - printerr(0, "WARNING: %s: failed reading request\n", __func__);
> > - free_upcall_info(info);
> > - return;
> > - }
> > - info->lbuf[info->lbuflen-1] = 0;
> > -
> > - if (start_upcall_thread(handle_gssd_upcall, info))
> > - free_upcall_info(info);
> > + handle_gssd_upcall(clp);
> > }
> >
> > static void
> > gssd_clnt_krb5_cb(int UNUSED(fd), short UNUSED(which), void *data)
> > {
> > struct clnt_info *clp = data;
> > - struct clnt_upcall_info *info;
> > -
> > - info = alloc_upcall_info(clp);
> > - if (info == NULL)
> > - return;
> > -
> > - if (read(clp->krb5_fd, &info->uid,
> > - sizeof(info->uid)) < (ssize_t)sizeof(info->uid)) {
> > - printerr(0, "WARNING: %s: failed reading uid from krb5 "
> > - "upcall pipe: %s\n", __func__, strerror(errno));
> > - free_upcall_info(info);
> > - return;
> > - }
> >
> > - if (start_upcall_thread(handle_krb5_upcall, info))
> > - free_upcall_info(info);
> > + handle_krb5_upcall(clp);
> > }
> >
> > static struct clnt_info *
> > diff --git a/utils/gssd/gssd.h b/utils/gssd/gssd.h
> > index 1e8c58d4..6d53647e 100644
> > --- a/utils/gssd/gssd.h
> > +++ b/utils/gssd/gssd.h
> > @@ -84,14 +84,17 @@ struct clnt_info {
> >
> > struct clnt_upcall_info {
> > struct clnt_info *clp;
> > - char lbuf[RPC_CHAN_BUF_SIZE];
> > - int lbuflen;
> > uid_t uid;
> > + int fd;
> > + char *srchost;
> > + char *target;
> > + char *service;
> > };
> >
> > -void handle_krb5_upcall(struct clnt_upcall_info *clp);
> > -void handle_gssd_upcall(struct clnt_upcall_info *clp);
> > +void handle_krb5_upcall(struct clnt_info *clp);
> > +void handle_gssd_upcall(struct clnt_info *clp);
> > void free_upcall_info(struct clnt_upcall_info *info);
> > +void gssd_free_client(struct clnt_info *clp);
> >
> >
> > #endif /* _RPC_GSSD_H_ */
> > diff --git a/utils/gssd/gssd_proc.c b/utils/gssd/gssd_proc.c
> > index e830f497..ba508b30 100644
> > --- a/utils/gssd/gssd_proc.c
> > +++ b/utils/gssd/gssd_proc.c
> > @@ -80,6 +80,8 @@
> > #include "nfslib.h"
> > #include "gss_names.h"
> >
> > +extern pthread_mutex_t clp_lock;
> > +
> > /* Encryption types supported by the kernel rpcsec_gss code */
> > int num_krb5_enctypes = 0;
> > krb5_enctype *krb5_enctypes = NULL;
> > @@ -723,22 +725,135 @@ out_return_error:
> > goto out;
> > }
> >
> > -void
> > -handle_krb5_upcall(struct clnt_upcall_info *info)
> > +static struct clnt_upcall_info *
> > +alloc_upcall_info(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
> > + char *target, char *service)
> > {
> > - struct clnt_info *clp = info->clp;
> > + struct clnt_upcall_info *info;
> > +
> > + info = malloc(sizeof(struct clnt_upcall_info));
> > + if (info == NULL)
> > + return NULL;
> > +
> > + memset(info, 0, sizeof(*info));
> > + pthread_mutex_lock(&clp_lock);
> > + clp->refcount++;
> > + pthread_mutex_unlock(&clp_lock);
> > + info->clp = clp;
> > + info->uid = uid;
> > + info->fd = fd;
> > + if (srchost) {
> > + info->srchost = strdup(srchost);
> > + if (info->srchost == NULL)
> > + goto out_info;
> > + }
> > + if (target) {
> > + info->target = strdup(target);
> > + if (info->target == NULL)
> > + goto out_srchost;
> > + }
> > + if (service) {
> > + info->service = strdup(service);
> > + if (info->service == NULL)
> > + goto out_target;
> > + }
> > +
> > +out:
> > + return info;
> > +
> > +out_target:
> > + if (info->target)
> > + free(info->target);
> > +out_srchost:
> > + if (info->srchost)
> > + free(info->srchost);
> > +out_info:
> > + free(info);
> > + info = NULL;
> > + goto out;
> > +}
> >
> > - printerr(2, "\n%s: uid %d (%s)\n", __func__, info->uid, clp->relpath);
> > +void free_upcall_info(struct clnt_upcall_info *info)
> > +{
> > + gssd_free_client(info->clp);
> > + if (info->service)
> > + free(info->service);
> > + if (info->target)
> > + free(info->target);
> > + if (info->srchost)
> > + free(info->srchost);
> > + free(info);
> > +}
> >
> > - process_krb5_upcall(clp, info->uid, clp->krb5_fd, NULL, NULL, NULL);
> > +static void
> > +gssd_work_thread_fn(struct clnt_upcall_info *info)
> > +{
> > + process_krb5_upcall(info->clp, info->uid, info->fd, info->srchost, info->target, info->service);
> > free_upcall_info(info);
> > }
> >
> > +static int
> > +start_upcall_thread(void (*func)(struct clnt_upcall_info *), void *info)
> > +{
> > + pthread_attr_t attr;
> > + pthread_t th;
> > + int ret;
> > +
> > + ret = pthread_attr_init(&attr);
> > + if (ret != 0) {
> > + printerr(0, "ERROR: failed to init pthread attr: ret %d: %s\n",
> > + ret, strerror(errno));
> > + return ret;
> > + }
> > + ret = pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED);
> > + if (ret != 0) {
> > + printerr(0, "ERROR: failed to create pthread attr: ret %d: "
> > + "%s\n", ret, strerror(errno));
> > + return ret;
> > + }
> > +
> > + ret = pthread_create(&th, &attr, (void *)func, (void *)info);
> > + if (ret != 0)
> > + printerr(0, "ERROR: pthread_create failed: ret %d: %s\n",
> > + ret, strerror(errno));
> > + else
> > + printerr(0, "created thread id 0x%lx\n", th);
> printerr(0) are used for errors not debugging... But I'm wondering
> if this debug statement is even needed... Since we tids are not
> included in other debugging statements, how would they info be useful?

In the 2nd patch I actually changed it to printerr(1), but yeah we can get
rid of it. I had a ton of these sprinkled all over the place and for
some reason decided to keep this one.

>
>
> > + return ret;
> > +}
> > +
> > +void
> > +handle_krb5_upcall(struct clnt_info *clp)
> > +{
> > + uid_t uid;
> > + struct clnt_upcall_info *info;
> > + int err;
> > +
> > + if (read(clp->krb5_fd, &uid, sizeof(uid)) < (ssize_t)sizeof(uid)) {
> > + printerr(0, "WARNING: failed reading uid from krb5 "
> > + "upcall pipe: %s\n", strerror(errno));
> > + return;
> > + }
> > + printerr(2, "\n%s: uid %d (%s)\n", __func__, uid, clp->relpath);
> > +
> > + info = alloc_upcall_info(clp, uid, clp->krb5_fd, NULL, NULL, NULL);
> > + if (info == NULL) {
> > + printerr(0, "%s: failed to allocate clnt_upcall_info\n", __func__);
> > + do_error_downcall(clp->krb5_fd, uid, -EACCES);
> > + return;
> > + }
> > + err = start_upcall_thread(gssd_work_thread_fn, info);
> > + if (err != 0) {
> > + do_error_downcall(clp->krb5_fd, uid, -EACCES);
> > + free_upcall_info(info);
> > + }
> > +}
> Why is -EACCES being used in both failures? Shouldn't errno be used
> or at least ENOMEM for the alloc_upcall_info() failure?

I believe the code that handles the downcall in the kernel only looks
for -EACCES and -EKEYEXPIRED. Anything else gets translated to -EACCES,
so that's why I went ahead and used -EACCES (see gss_fill_context()).

Note that means the kernel will also translate -ETIMEDOUT (from the 2nd
patch) to -EACCES as well... but I don't think it's necessary to change
that behavior really.

-Scott
>
> Again... these are just nits.. so a repost is not necessary
> Just wanted to get your thoughts on them.
>
> steved.
>
> > +
> > void
> > -handle_gssd_upcall(struct clnt_upcall_info *info)
> > +handle_gssd_upcall(struct clnt_info *clp)
> > {
> > - struct clnt_info *clp = info->clp;
> > uid_t uid;
> > + char lbuf[RPC_CHAN_BUF_SIZE];
> > + int lbuflen = 0;
> > char *p;
> > char *mech = NULL;
> > char *uidstr = NULL;
> > @@ -746,20 +861,22 @@ handle_gssd_upcall(struct clnt_upcall_info *info)
> > char *service = NULL;
> > char *srchost = NULL;
> > char *enctypes = NULL;
> > - char *upcall_str;
> > - char *pbuf = info->lbuf;
> > pthread_t tid = pthread_self();
> > + struct clnt_upcall_info *info;
> > + int err;
> >
> > - printerr(2, "\n%s(0x%x): '%s' (%s)\n", __func__, tid,
> > - info->lbuf, clp->relpath);
> > -
> > - upcall_str = strdup(info->lbuf);
> > - if (upcall_str == NULL) {
> > - printerr(0, "ERROR: malloc failure\n");
> > - goto out_nomem;
> > + lbuflen = read(clp->gssd_fd, lbuf, sizeof(lbuf));
> > + if (lbuflen <= 0 || lbuf[lbuflen-1] != '\n') {
> > + printerr(0, "WARNING: handle_gssd_upcall: "
> > + "failed reading request\n");
> > + return;
> > }
> > + lbuf[lbuflen-1] = 0;
> > +
> > + printerr(2, "\n%s(0x%x): '%s' (%s)\n", __func__, tid,
> > + lbuf, clp->relpath);
> >
> > - while ((p = strsep(&pbuf, " "))) {
> > + for (p = strtok(lbuf, " "); p; p = strtok(NULL, " ")) {
> > if (!strncmp(p, "mech=", strlen("mech=")))
> > mech = p + strlen("mech=");
> > else if (!strncmp(p, "uid=", strlen("uid=")))
> > @@ -777,8 +894,8 @@ handle_gssd_upcall(struct clnt_upcall_info *info)
> > if (!mech || strlen(mech) < 1) {
> > printerr(0, "WARNING: handle_gssd_upcall: "
> > "failed to find gss mechanism name "
> > - "in upcall string '%s'\n", upcall_str);
> > - goto out;
> > + "in upcall string '%s'\n", lbuf);
> > + return;
> > }
> >
> > if (uidstr) {
> > @@ -790,21 +907,21 @@ handle_gssd_upcall(struct clnt_upcall_info *info)
> > if (!uidstr) {
> > printerr(0, "WARNING: handle_gssd_upcall: "
> > "failed to find uid "
> > - "in upcall string '%s'\n", upcall_str);
> > - goto out;
> > + "in upcall string '%s'\n", lbuf);
> > + return;
> > }
> >
> > if (enctypes && parse_enctypes(enctypes) != 0) {
> > printerr(0, "WARNING: handle_gssd_upcall: "
> > "parsing encryption types failed: errno %d\n", errno);
> > - goto out;
> > + return;
> > }
> >
> > if (target && strlen(target) < 1) {
> > printerr(0, "WARNING: handle_gssd_upcall: "
> > "failed to parse target name "
> > - "in upcall string '%s'\n", upcall_str);
> > - goto out;
> > + "in upcall string '%s'\n", lbuf);
> > + return;
> > }
> >
> > /*
> > @@ -818,21 +935,26 @@ handle_gssd_upcall(struct clnt_upcall_info *info)
> > if (service && strlen(service) < 1) {
> > printerr(0, "WARNING: handle_gssd_upcall: "
> > "failed to parse service type "
> > - "in upcall string '%s'\n", upcall_str);
> > - goto out;
> > + "in upcall string '%s'\n", lbuf);
> > + return;
> > }
> >
> > - if (strcmp(mech, "krb5") == 0 && clp->servername)
> > - process_krb5_upcall(clp, uid, clp->gssd_fd, srchost, target, service);
> > - else {
> > + if (strcmp(mech, "krb5") == 0 && clp->servername) {
> > + info = alloc_upcall_info(clp, uid, clp->gssd_fd, srchost, target, service);
> > + if (info == NULL) {
> > + printerr(0, "%s: failed to allocate clnt_upcall_info\n", __func__);
> > + do_error_downcall(clp->gssd_fd, uid, -EACCES);
> > + return;
> > + }
> > + err = start_upcall_thread(gssd_work_thread_fn, info);
> > + if (err != 0) {
> > + do_error_downcall(clp->gssd_fd, uid, -EACCES);
> > + free_upcall_info(info);
> > + }
> > + } else {
> > if (clp->servername)
> > printerr(0, "WARNING: handle_gssd_upcall: "
> > "received unknown gss mech '%s'\n", mech);
> > do_error_downcall(clp->gssd_fd, uid, -EACCES);
> > }
> > -out:
> > - free(upcall_str);
> > -out_nomem:
> > - free_upcall_info(info);
> > - return;
> > }
> >
>

2021-05-26 19:10:47

by Steve Dickson

[permalink] [raw]
Subject: Re: [nfs-utils RFC PATCH 2/2] gssd: add timeout for upcall threads

Hey!

Again... a few very small teaks

On 5/25/21 2:00 PM, Scott Mayhew wrote:
> Add a global list of active upcalls and a watchdog thread that walks the
> list, looking for threads running longer than timeout seconds. By
> default, the watchdog thread will cancel these threads and report an
> error of -ETIMEDOUT to the kernel. Passing the -C option or setting
> cancel-timed-out-upcalls=0 in nfs.conf disables this behavior and
> causes the watchdog thread to simply log an error message instead. The
> upcall timeout can be specified by passing the -U option or by setting
> the upcall-timeout parameter in nfs.conf.
>
> Signed-off-by: Scott Mayhew <[email protected]>
> ---
> nfs.conf | 2 +
> utils/gssd/gssd.c | 125 +++++++++++++++++++++++++++++++++++++++-
> utils/gssd/gssd.h | 15 +++++
> utils/gssd/gssd.man | 31 +++++++++-
> utils/gssd/gssd_proc.c | 127 ++++++++++++++++++++++++++++++++---------
> 5 files changed, 270 insertions(+), 30 deletions(-)
>
> diff --git a/nfs.conf b/nfs.conf
> index 31994f61..7a987788 100644
> --- a/nfs.conf
> +++ b/nfs.conf
> @@ -25,6 +25,8 @@
> # cred-cache-directory=
> # preferred-realm=
> # set-home=1
> +# upcall-timeout=30
> +# cancel-timed-out-upcalls=1
> #
> [lockd]
> # port=0
> diff --git a/utils/gssd/gssd.c b/utils/gssd/gssd.c
> index eb440470..54a1ea3f 100644
> --- a/utils/gssd/gssd.c
> +++ b/utils/gssd/gssd.c
> @@ -95,9 +95,15 @@ static bool use_gssproxy = false;
> pthread_mutex_t clp_lock = PTHREAD_MUTEX_INITIALIZER;
> static bool signal_received = false;
> static struct event_base *evbase = NULL;
> +pthread_mutex_t active_thread_list_lock = PTHREAD_MUTEX_INITIALIZER;
> +
> +int upcall_timeout = DEF_UPCALL_TIMEOUT;
> +static bool cancel_timed_out_upcalls = true;
>
> TAILQ_HEAD(topdir_list_head, topdir) topdir_list;
>
> +TAILQ_HEAD(active_thread_list_head, upcall_thread_info) active_thread_list;
> +
> struct topdir {
> TAILQ_ENTRY(topdir) list;
> TAILQ_HEAD(clnt_list_head, clnt_info) clnt_list;
> @@ -436,6 +442,100 @@ gssd_clnt_krb5_cb(int UNUSED(fd), short UNUSED(which), void *data)
> handle_krb5_upcall(clp);
> }
>
> +static int
> +scan_active_thread_list(void)
> +{
> + struct upcall_thread_info *info;
> + struct timespec now;
> + unsigned int sleeptime;
> + bool sleeptime_set = false;
> + int err;
> + void *tret, *saveprev;
> +
> + sleeptime = upcall_timeout;
> + pthread_mutex_lock(&active_thread_list_lock);
> + clock_gettime(CLOCK_MONOTONIC, &now);
> + TAILQ_FOREACH(info, &active_thread_list, list) {
> + err = pthread_tryjoin_np(info->tid, &tret);
> + switch (err) {
> + case 0:
> + if (tret == PTHREAD_CANCELED)
> + printerr(3, "watchdog: thread id 0x%lx cancelled successfully\n",
> + info->tid);
> + saveprev = info->list.tqe_prev;
> + TAILQ_REMOVE(&active_thread_list, info, list);
> + free(info);
> + info = saveprev;
> + break;
> + case EBUSY:
> + if (now.tv_sec >= info->timeout.tv_sec) {
> + if (cancel_timed_out_upcalls && !info->cancelled) {
> + printerr(0, "watchdog: thread id 0x%lx timed out\n",
> + info->tid);
> + pthread_cancel(info->tid);
> + info->cancelled = true;
> + do_error_downcall(info->fd, info->uid, -ETIMEDOUT);
> + } else {
> + printerr(0, "watchdog: thread id 0x%lx running for %ld seconds\n",
> + info->tid,
> + now.tv_sec - info->timeout.tv_sec + upcall_timeout);
If people are going to used the -C flag they are saying they want
to ignore hung threads so I'm thinking with printerr(0) we would
be filling up their logs about messages they don't care about.
So I'm thinking we should change this to a printerr(1)

> + }
> + } else if (!sleeptime_set) {
> + sleeptime = info->timeout.tv_sec - now.tv_sec;
> + sleeptime_set = true;
> + }
> + break;
> + default:
> + printerr(0, "watchdog: attempt to join thread id 0x%lx returned %d (%s)!\n",
> + info->tid, err, strerror(err));
> + break;
> + }
> + }
> + pthread_mutex_unlock(&active_thread_list_lock);
> +
> + return sleeptime;
> +}
> +
> +static void *
> +watchdog_thread_fn(void *UNUSED(arg))
> +{
> + unsigned int sleeptime;
> +
> + for (;;) {
> + sleeptime = scan_active_thread_list();
> + printerr(4, "watchdog: sleeping %u secs\n", sleeptime);
> + sleep(sleeptime);
> + }
> + return (void *)0;
> +}
> +
> +static int
> +start_watchdog_thread(void)
> +{
> + pthread_attr_t attr;
> + pthread_t th;
> + int ret;
> +
> + ret = pthread_attr_init(&attr);
> + if (ret != 0) {
> + printerr(0, "ERROR: failed to init pthread attr: ret %d: %s\n",
> + ret, strerror(errno));
> + return ret;
> + }
> + ret = pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED);
> + if (ret != 0) {
> + printerr(0, "ERROR: failed to create pthread attr: ret %d: %s\n",
> + ret, strerror(errno));
> + return ret;
> + }
> + ret = pthread_create(&th, &attr, watchdog_thread_fn, NULL);
> + if (ret != 0) {
> + printerr(0, "ERROR: pthread_create failed: ret %d: %s\n",
> + ret, strerror(errno));
> + }
> + return ret;
> +}
> +
> static struct clnt_info *
> gssd_get_clnt(struct topdir *tdi, const char *name)
> {
> @@ -825,7 +925,7 @@ sig_die(int signal)
> static void
> usage(char *progname)
> {
> - fprintf(stderr, "usage: %s [-f] [-l] [-M] [-n] [-v] [-r] [-p pipefsdir] [-k keytab] [-d ccachedir] [-t timeout] [-R preferred realm] [-D] [-H]\n",
> + fprintf(stderr, "usage: %s [-f] [-l] [-M] [-n] [-v] [-r] [-p pipefsdir] [-k keytab] [-d ccachedir] [-t timeout] [-R preferred realm] [-D] [-H] [-U upcall timeout] [-C]\n",
> progname);
> exit(1);
> }
> @@ -846,6 +946,9 @@ read_gss_conf(void)
> #endif
> context_timeout = conf_get_num("gssd", "context-timeout", context_timeout);
> rpc_timeout = conf_get_num("gssd", "rpc-timeout", rpc_timeout);
> + upcall_timeout = conf_get_num("gssd", "upcall-timeout", upcall_timeout);
> + cancel_timed_out_upcalls = conf_get_bool("gssd", "cancel-timed-out-upcalls",
> + cancel_timed_out_upcalls);
> s = conf_get_str("gssd", "pipefs-directory");
> if (!s)
> s = conf_get_str("general", "pipefs-directory");
> @@ -887,7 +990,7 @@ main(int argc, char *argv[])
> verbosity = conf_get_num("gssd", "verbosity", verbosity);
> rpc_verbosity = conf_get_num("gssd", "rpc-verbosity", rpc_verbosity);
>
> - while ((opt = getopt(argc, argv, "HDfvrlmnMp:k:d:t:T:R:")) != -1) {
> + while ((opt = getopt(argc, argv, "HDfvrlmnMp:k:d:t:T:R:U:C")) != -1) {
> switch (opt) {
> case 'f':
> fg = 1;
> @@ -938,6 +1041,11 @@ main(int argc, char *argv[])
> case 'H':
> set_home = false;
> break;
> + case 'U':
> + upcall_timeout = atoi(optarg);
> + break;
> + case 'C':
> + cancel_timed_out_upcalls = false;
> default:
> usage(argv[0]);
> break;
> @@ -1010,6 +1118,11 @@ main(int argc, char *argv[])
> else
> progname = argv[0];
>
> + if (upcall_timeout > MAX_UPCALL_TIMEOUT)
> + upcall_timeout = MAX_UPCALL_TIMEOUT;
> + else if (upcall_timeout < MIN_UPCALL_TIMEOUT)
> + upcall_timeout = MIN_UPCALL_TIMEOUT;
> +
> initerr(progname, verbosity, fg);
> #ifdef HAVE_LIBTIRPC_SET_DEBUG
> /*
> @@ -1068,6 +1181,14 @@ main(int argc, char *argv[])
> }
> event_add(inotify_ev, NULL);
>
> + TAILQ_INIT(&active_thread_list);
> +
> + rc = start_watchdog_thread();
> + if (rc != 0) {
> + printerr(0, "ERROR: failed to start watchdog thread: %d\n", rc);
> + exit(EXIT_FAILURE);
> + }
> +
> TAILQ_INIT(&topdir_list);
> gssd_scan();
> daemon_ready();
> diff --git a/utils/gssd/gssd.h b/utils/gssd/gssd.h
> index 6d53647e..ad0d1d93 100644
> --- a/utils/gssd/gssd.h
> +++ b/utils/gssd/gssd.h
> @@ -50,6 +50,11 @@
> #define GSSD_DEFAULT_KEYTAB_FILE "/etc/krb5.keytab"
> #define GSSD_SERVICE_NAME "nfs"
> #define RPC_CHAN_BUF_SIZE 32768
> +
I think we should add a "/* seconds */"
so you don't have dig in the code
to see what interval is
> +#define MIN_UPCALL_TIMEOUT 5
> +#define DEF_UPCALL_TIMEOUT 30
> +#define MAX_UPCALL_TIMEOUT 600
> +
> /*
> * The gss mechanisms that we can handle
> */
> @@ -91,10 +96,20 @@ struct clnt_upcall_info {
> char *service;
> };
>
> +struct upcall_thread_info {
> + TAILQ_ENTRY(upcall_thread_info) list;
> + pthread_t tid;
> + struct timespec timeout;
> + uid_t uid;
> + int fd;
> + bool cancelled;
> +};
> +
> void handle_krb5_upcall(struct clnt_info *clp);
> void handle_gssd_upcall(struct clnt_info *clp);
> void free_upcall_info(struct clnt_upcall_info *info);
> void gssd_free_client(struct clnt_info *clp);
> +int do_error_downcall(int k5_fd, uid_t uid, int err);
>
>
> #endif /* _RPC_GSSD_H_ */
> diff --git a/utils/gssd/gssd.man b/utils/gssd/gssd.man
> index 9ae6def9..20fea729 100644
> --- a/utils/gssd/gssd.man
> +++ b/utils/gssd/gssd.man
> @@ -8,7 +8,7 @@
> rpc.gssd \- RPCSEC_GSS daemon
> .SH SYNOPSIS
> .B rpc.gssd
> -.RB [ \-DfMnlvrH ]
> +.RB [ \-DfMnlvrHC ]
> .RB [ \-k
> .IR keytab ]
> .RB [ \-p
> @@ -17,6 +17,10 @@ rpc.gssd \- RPCSEC_GSS daemon
> .IR ccachedir ]
> .RB [ \-t
> .IR timeout ]
> +.RB [ \-T
> +.IR timeout ]
> +.RB [ \-U
> +.IR timeout ]
> .RB [ \-R
> .IR realm ]
> .SH INTRODUCTION
> @@ -275,7 +279,7 @@ seconds, which allows changing Kerberos tickets and identities frequently.
> The default is no explicit timeout, which means the kernel context will live
> the lifetime of the Kerberos service ticket used in its creation.
> .TP
> -.B -T timeout
> +.BI "-T " timeout
> Timeout, in seconds, to create an RPC connection with a server while
> establishing an authenticated gss context for a user.
> The default timeout is set to 5 seconds.
> @@ -283,6 +287,18 @@ If you get messages like "WARNING: can't create tcp rpc_clnt to server
> %servername% for user with uid %uid%: RPC: Remote system error -
> Connection timed out", you should consider an increase of this timeout.
> .TP
> +.BI "-U " timeout
> +Timeout, in seconds, for upcall threads. Threads executing longer than
> +.I timeout
> +seconds will be cancelled and an error of -ETIMEDOUT will be reported
> +to the kernel. The default
> +.I timeout
> +is 30 seconds. The minimum is 5 seconds. The maximum is 600 seconds.
> +.TP
> +.B -C
> +Instead of cancelling upcall threads that have timed out, cause an error
> +message to be logged to the syslog (no error will be reported to the kernel).
> +.TP
> .B -H
> Avoids setting $HOME to "/". This allows rpc.gssd to read per user k5identity
> files versus trying to read /.k5identity for each user.
> @@ -350,6 +366,17 @@ Equivalent to
> Equivalent to
> .BR -R .
> .TP
> +.B upcall-timeout
> +Equivalent to
> +.BR -U .
> +.TP
> +.B cancel-timed-out-upcalls
> +Setting to
> +.B false
> +is equivalent to providing the
> +.B -C
> +flag.
> +.TP
> .B set-home
> Setting to
> .B false
> diff --git a/utils/gssd/gssd_proc.c b/utils/gssd/gssd_proc.c
> index ba508b30..ac7b1d1c 100644
> --- a/utils/gssd/gssd_proc.c
> +++ b/utils/gssd/gssd_proc.c
> @@ -81,11 +81,23 @@
> #include "gss_names.h"
>
> extern pthread_mutex_t clp_lock;
> +extern pthread_mutex_t active_thread_list_lock;
> +extern int upcall_timeout;
> +extern TAILQ_HEAD(active_thread_list_head, upcall_thread_info) active_thread_list;
>
> /* Encryption types supported by the kernel rpcsec_gss code */
> int num_krb5_enctypes = 0;
> krb5_enctype *krb5_enctypes = NULL;
>
> +struct cleanup_args {
> + OM_uint32 *min_stat;
> + gss_buffer_t acceptor;
> + gss_buffer_t token;
> + struct authgss_private_data *pd;
> + AUTH **auth;
> + CLIENT **rpc_clnt;
> +};
> +
> /*
> * Parse the supported encryption type information
> */
> @@ -184,7 +196,7 @@ out_err:
> return;
> }
>
> -static int
> +int
> do_error_downcall(int k5_fd, uid_t uid, int err)
> {
> char buf[1024];
> @@ -607,14 +619,37 @@ out:
> return auth;
> }
>
> +static void
> +cleanup_handler(void *arg)
> +{
> + struct cleanup_args *args = (struct cleanup_args *)arg;
> +
> + gss_release_buffer(args->min_stat, args->acceptor);
> + if (args->token->value)
> + free(args->token->value);
> +#ifdef HAVE_AUTHGSS_FREE_PRIVATE_DATA
> + if (args->pd->pd_ctx_hndl.length != 0 || args->pd->pd_ctx != 0)
> + authgss_free_private_data(args->pd);
> +#endif
> + if (*args->auth)
> + AUTH_DESTROY(*args->auth);
> + if (*args->rpc_clnt)
> + clnt_destroy(*args->rpc_clnt);
> +}
> +
> /*
> * this code uses the userland rpcsec gss library to create a krb5
> * context on behalf of the kernel
> */
> static void
> -process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
> - char *tgtname, char *service)
> +process_krb5_upcall(struct clnt_upcall_info *info)
> {
> + struct clnt_info *clp = info->clp;
> + uid_t uid = info->uid;
> + int fd = info->fd;
> + char *srchost = info->srchost;
> + char *tgtname = info->target;
> + char *service = info->service;
> CLIENT *rpc_clnt = NULL;
> AUTH *auth = NULL;
> struct authgss_private_data pd;
> @@ -624,11 +659,13 @@ process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
> gss_name_t gacceptor = GSS_C_NO_NAME;
> gss_OID mech;
> gss_buffer_desc acceptor = {0};
> + struct cleanup_args cleanup_args = {&min_stat, &acceptor, &token, &pd, &auth, &rpc_clnt};
>
> token.length = 0;
> token.value = NULL;
> memset(&pd, 0, sizeof(struct authgss_private_data));
>
> + pthread_cleanup_push(cleanup_handler, &cleanup_args);
> /*
> * If "service" is specified, then the kernel is indicating that
> * we must use machine credentials for this request. (Regardless
> @@ -650,6 +687,7 @@ process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
> * used for this case is not important.
> *
> */
> + pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);
> if (uid != 0 || (uid == 0 && root_uses_machine_creds == 0 &&
> service == NULL)) {
>
> @@ -670,15 +708,21 @@ process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
> goto out_return_error;
> }
> }
> + pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
> + pthread_testcancel();
>
> + pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);
> if (!authgss_get_private_data(auth, &pd)) {
> printerr(1, "WARNING: Failed to obtain authentication "
> "data for user with uid %d for server %s\n",
> uid, clp->servername);
> goto out_return_error;
> }
> + pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
> + pthread_testcancel();
>
> /* Grab the context lifetime and acceptor name out of the ctx. */
> + pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);
> maj_stat = gss_inquire_context(&min_stat, pd.pd_ctx, NULL, &gacceptor,
> &lifetime_rec, &mech, NULL, NULL, NULL);
>
> @@ -690,37 +734,35 @@ process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
> get_hostbased_client_buffer(gacceptor, mech, &acceptor);
> gss_release_name(&min_stat, &gacceptor);
> }
> + pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
> + pthread_testcancel();
>
> /*
> * The serialization can mean turning pd.pd_ctx into a lucid context. If
> * that happens then the pd.pd_ctx will be unusable, so we must never
> * try to use it after this point.
> */
> + pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);
> if (serialize_context_for_kernel(&pd.pd_ctx, &token, &krb5oid, NULL)) {
> printerr(1, "WARNING: Failed to serialize krb5 context for "
> "user with uid %d for server %s\n",
> uid, clp->servername);
> goto out_return_error;
> }
> + pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
> + pthread_testcancel();
>
> do_downcall(fd, uid, &pd, &token, lifetime_rec, &acceptor);
>
> out:
> - gss_release_buffer(&min_stat, &acceptor);
> - if (token.value)
> - free(token.value);
> -#ifdef HAVE_AUTHGSS_FREE_PRIVATE_DATA
> - if (pd.pd_ctx_hndl.length != 0 || pd.pd_ctx != 0)
> - authgss_free_private_data(&pd);
> -#endif
> - if (auth)
> - AUTH_DESTROY(auth);
> - if (rpc_clnt)
> - clnt_destroy(rpc_clnt);
> + pthread_cleanup_pop(1);
>
> return;
>
> out_return_error:
> + pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
> + pthread_testcancel();
> +
> do_error_downcall(fd, uid, downcall_err);
> goto out;
> }
> @@ -786,38 +828,71 @@ void free_upcall_info(struct clnt_upcall_info *info)
> }
>
> static void
> -gssd_work_thread_fn(struct clnt_upcall_info *info)
> +cleanup_clnt_upcall_info(void *arg)
> {
> - process_krb5_upcall(info->clp, info->uid, info->fd, info->srchost, info->target, info->service);
> + struct clnt_upcall_info *info = (struct clnt_upcall_info *)arg;
> +
> free_upcall_info(info);
> }
>
> +static void
> +gssd_work_thread_fn(struct clnt_upcall_info *info)
> +{
> + pthread_cleanup_push(cleanup_clnt_upcall_info, info);
> + process_krb5_upcall(info);
> + pthread_cleanup_pop(1);
> +}
> +
> +static struct upcall_thread_info *
> +alloc_upcall_thread_info(void)
> +{
> + struct upcall_thread_info *info;
> +
> + info = malloc(sizeof(struct upcall_thread_info));
> + if (info == NULL)
> + return NULL;
> + memset(info, 0, sizeof(*info));
> + return info;
> +}
> +
> static int
> -start_upcall_thread(void (*func)(struct clnt_upcall_info *), void *info)
> +start_upcall_thread(void (*func)(struct clnt_upcall_info *), struct clnt_upcall_info *info)
> {
> pthread_attr_t attr;
> pthread_t th;
> + struct upcall_thread_info *tinfo;
> int ret;
>
> + tinfo = alloc_upcall_thread_info();
> + if (!tinfo)
> + return -ENOMEM;
> + tinfo->fd = info->fd;
> + tinfo->uid = info->uid;
> + tinfo->cancelled = false;
> +
> ret = pthread_attr_init(&attr);
> if (ret != 0) {
> printerr(0, "ERROR: failed to init pthread attr: ret %d: %s\n",
> ret, strerror(errno));
> - return ret;
> - }
> - ret = pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED);
> - if (ret != 0) {
> - printerr(0, "ERROR: failed to create pthread attr: ret %d: "
> - "%s\n", ret, strerror(errno));
> + free(tinfo);
> return ret;
> }
>
> ret = pthread_create(&th, &attr, (void *)func, (void *)info);
> - if (ret != 0)
> + if (ret != 0) {
> printerr(0, "ERROR: pthread_create failed: ret %d: %s\n",
> ret, strerror(errno));
> - else
> - printerr(0, "created thread id 0x%lx\n", th);
> + free(tinfo);
> + return ret;
> + }
> + printerr(1, "created thread id 0x%lx\n", th);
This will be removed...
> + tinfo->tid = th;
> + pthread_mutex_lock(&active_thread_list_lock);
> + clock_gettime(CLOCK_MONOTONIC, &tinfo->timeout);
> + tinfo->timeout.tv_sec += upcall_timeout;
> + TAILQ_INSERT_TAIL(&active_thread_list, tinfo, list);
> + pthread_mutex_unlock(&active_thread_list_lock);
> +
> return ret;
> }
>
>

Overall I think the code is very well written with
one exception... The lack of comments. I think it
would be very useful to let the reader know what
you are doing and why.... But by no means is
that a show stopper. Nice work!

I'm still doing more testing and nothing
is breaking... So it is looking pretty good!

steved.

2021-05-26 19:11:37

by Chuck Lever

[permalink] [raw]
Subject: Re: [nfs-utils RFC PATCH 2/2] gssd: add timeout for upcall threads

Hi Scott-


> On May 26, 2021, at 1:08 PM, Steve Dickson <[email protected]> wrote:
>
> Hey!
>
> Again... a few very small teaks
>
> On 5/25/21 2:00 PM, Scott Mayhew wrote:
>> Add a global list of active upcalls and a watchdog thread that walks the
>> list, looking for threads running longer than timeout seconds. By
>> default, the watchdog thread will cancel these threads and report an
>> error of -ETIMEDOUT to the kernel. Passing the -C option or setting
>> cancel-timed-out-upcalls=0 in nfs.conf disables this behavior and
>> causes the watchdog thread to simply log an error message instead. The
>> upcall timeout can be specified by passing the -U option or by setting
>> the upcall-timeout parameter in nfs.conf.

Not a critique of this patch, but I'm wondering if there's any
way to get a sense of why each stuck thread was hung so we (or
the local admin) can understand the underlying problems. Maybe
that's something for another day.


>> Signed-off-by: Scott Mayhew <[email protected]>
>> ---
>> nfs.conf | 2 +
>> utils/gssd/gssd.c | 125 +++++++++++++++++++++++++++++++++++++++-
>> utils/gssd/gssd.h | 15 +++++
>> utils/gssd/gssd.man | 31 +++++++++-
>> utils/gssd/gssd_proc.c | 127 ++++++++++++++++++++++++++++++++---------
>> 5 files changed, 270 insertions(+), 30 deletions(-)
>>
>> diff --git a/nfs.conf b/nfs.conf
>> index 31994f61..7a987788 100644
>> --- a/nfs.conf
>> +++ b/nfs.conf
>> @@ -25,6 +25,8 @@
>> # cred-cache-directory=
>> # preferred-realm=
>> # set-home=1
>> +# upcall-timeout=30
>> +# cancel-timed-out-upcalls=1
>> #
>> [lockd]
>> # port=0
>> diff --git a/utils/gssd/gssd.c b/utils/gssd/gssd.c
>> index eb440470..54a1ea3f 100644
>> --- a/utils/gssd/gssd.c
>> +++ b/utils/gssd/gssd.c
>> @@ -95,9 +95,15 @@ static bool use_gssproxy = false;
>> pthread_mutex_t clp_lock = PTHREAD_MUTEX_INITIALIZER;
>> static bool signal_received = false;
>> static struct event_base *evbase = NULL;
>> +pthread_mutex_t active_thread_list_lock = PTHREAD_MUTEX_INITIALIZER;
>> +
>> +int upcall_timeout = DEF_UPCALL_TIMEOUT;
>> +static bool cancel_timed_out_upcalls = true;
>>
>> TAILQ_HEAD(topdir_list_head, topdir) topdir_list;
>>
>> +TAILQ_HEAD(active_thread_list_head, upcall_thread_info) active_thread_list;
>> +
>> struct topdir {
>> TAILQ_ENTRY(topdir) list;
>> TAILQ_HEAD(clnt_list_head, clnt_info) clnt_list;
>> @@ -436,6 +442,100 @@ gssd_clnt_krb5_cb(int UNUSED(fd), short UNUSED(which), void *data)
>> handle_krb5_upcall(clp);
>> }
>>
>> +static int
>> +scan_active_thread_list(void)
>> +{
>> + struct upcall_thread_info *info;
>> + struct timespec now;
>> + unsigned int sleeptime;
>> + bool sleeptime_set = false;
>> + int err;
>> + void *tret, *saveprev;
>> +
>> + sleeptime = upcall_timeout;
>> + pthread_mutex_lock(&active_thread_list_lock);
>> + clock_gettime(CLOCK_MONOTONIC, &now);
>> + TAILQ_FOREACH(info, &active_thread_list, list) {
>> + err = pthread_tryjoin_np(info->tid, &tret);
>> + switch (err) {
>> + case 0:
>> + if (tret == PTHREAD_CANCELED)
>> + printerr(3, "watchdog: thread id 0x%lx cancelled successfully\n",
>> + info->tid);
>> + saveprev = info->list.tqe_prev;
>> + TAILQ_REMOVE(&active_thread_list, info, list);
>> + free(info);
>> + info = saveprev;
>> + break;
>> + case EBUSY:
>> + if (now.tv_sec >= info->timeout.tv_sec) {
>> + if (cancel_timed_out_upcalls && !info->cancelled) {
>> + printerr(0, "watchdog: thread id 0x%lx timed out\n",
>> + info->tid);
>> + pthread_cancel(info->tid);
>> + info->cancelled = true;
>> + do_error_downcall(info->fd, info->uid, -ETIMEDOUT);
>> + } else {
>> + printerr(0, "watchdog: thread id 0x%lx running for %ld seconds\n",
>> + info->tid,
>> + now.tv_sec - info->timeout.tv_sec + upcall_timeout);
> If people are going to used the -C flag they are saying they want
> to ignore hung threads so I'm thinking with printerr(0) we would
> be filling up their logs about messages they don't care about.
> So I'm thinking we should change this to a printerr(1)
>
>> + }
>> + } else if (!sleeptime_set) {
>> + sleeptime = info->timeout.tv_sec - now.tv_sec;
>> + sleeptime_set = true;
>> + }
>> + break;
>> + default:
>> + printerr(0, "watchdog: attempt to join thread id 0x%lx returned %d (%s)!\n",
>> + info->tid, err, strerror(err));
>> + break;
>> + }
>> + }
>> + pthread_mutex_unlock(&active_thread_list_lock);
>> +
>> + return sleeptime;
>> +}
>> +
>> +static void *
>> +watchdog_thread_fn(void *UNUSED(arg))
>> +{
>> + unsigned int sleeptime;
>> +
>> + for (;;) {
>> + sleeptime = scan_active_thread_list();
>> + printerr(4, "watchdog: sleeping %u secs\n", sleeptime);
>> + sleep(sleeptime);
>> + }
>> + return (void *)0;
>> +}
>> +
>> +static int
>> +start_watchdog_thread(void)
>> +{
>> + pthread_attr_t attr;
>> + pthread_t th;
>> + int ret;
>> +
>> + ret = pthread_attr_init(&attr);
>> + if (ret != 0) {
>> + printerr(0, "ERROR: failed to init pthread attr: ret %d: %s\n",
>> + ret, strerror(errno));
>> + return ret;
>> + }
>> + ret = pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED);
>> + if (ret != 0) {
>> + printerr(0, "ERROR: failed to create pthread attr: ret %d: %s\n",
>> + ret, strerror(errno));
>> + return ret;
>> + }
>> + ret = pthread_create(&th, &attr, watchdog_thread_fn, NULL);
>> + if (ret != 0) {
>> + printerr(0, "ERROR: pthread_create failed: ret %d: %s\n",
>> + ret, strerror(errno));
>> + }
>> + return ret;
>> +}
>> +
>> static struct clnt_info *
>> gssd_get_clnt(struct topdir *tdi, const char *name)
>> {
>> @@ -825,7 +925,7 @@ sig_die(int signal)
>> static void
>> usage(char *progname)
>> {
>> - fprintf(stderr, "usage: %s [-f] [-l] [-M] [-n] [-v] [-r] [-p pipefsdir] [-k keytab] [-d ccachedir] [-t timeout] [-R preferred realm] [-D] [-H]\n",
>> + fprintf(stderr, "usage: %s [-f] [-l] [-M] [-n] [-v] [-r] [-p pipefsdir] [-k keytab] [-d ccachedir] [-t timeout] [-R preferred realm] [-D] [-H] [-U upcall timeout] [-C]\n",
>> progname);
>> exit(1);
>> }
>> @@ -846,6 +946,9 @@ read_gss_conf(void)
>> #endif
>> context_timeout = conf_get_num("gssd", "context-timeout", context_timeout);
>> rpc_timeout = conf_get_num("gssd", "rpc-timeout", rpc_timeout);
>> + upcall_timeout = conf_get_num("gssd", "upcall-timeout", upcall_timeout);
>> + cancel_timed_out_upcalls = conf_get_bool("gssd", "cancel-timed-out-upcalls",
>> + cancel_timed_out_upcalls);
>> s = conf_get_str("gssd", "pipefs-directory");
>> if (!s)
>> s = conf_get_str("general", "pipefs-directory");
>> @@ -887,7 +990,7 @@ main(int argc, char *argv[])
>> verbosity = conf_get_num("gssd", "verbosity", verbosity);
>> rpc_verbosity = conf_get_num("gssd", "rpc-verbosity", rpc_verbosity);
>>
>> - while ((opt = getopt(argc, argv, "HDfvrlmnMp:k:d:t:T:R:")) != -1) {
>> + while ((opt = getopt(argc, argv, "HDfvrlmnMp:k:d:t:T:R:U:C")) != -1) {
>> switch (opt) {
>> case 'f':
>> fg = 1;
>> @@ -938,6 +1041,11 @@ main(int argc, char *argv[])
>> case 'H':
>> set_home = false;
>> break;
>> + case 'U':
>> + upcall_timeout = atoi(optarg);
>> + break;
>> + case 'C':
>> + cancel_timed_out_upcalls = false;
>> default:
>> usage(argv[0]);
>> break;
>> @@ -1010,6 +1118,11 @@ main(int argc, char *argv[])
>> else
>> progname = argv[0];
>>
>> + if (upcall_timeout > MAX_UPCALL_TIMEOUT)
>> + upcall_timeout = MAX_UPCALL_TIMEOUT;
>> + else if (upcall_timeout < MIN_UPCALL_TIMEOUT)
>> + upcall_timeout = MIN_UPCALL_TIMEOUT;
>> +
>> initerr(progname, verbosity, fg);
>> #ifdef HAVE_LIBTIRPC_SET_DEBUG
>> /*
>> @@ -1068,6 +1181,14 @@ main(int argc, char *argv[])
>> }
>> event_add(inotify_ev, NULL);
>>
>> + TAILQ_INIT(&active_thread_list);
>> +
>> + rc = start_watchdog_thread();
>> + if (rc != 0) {
>> + printerr(0, "ERROR: failed to start watchdog thread: %d\n", rc);
>> + exit(EXIT_FAILURE);
>> + }
>> +
>> TAILQ_INIT(&topdir_list);
>> gssd_scan();
>> daemon_ready();
>> diff --git a/utils/gssd/gssd.h b/utils/gssd/gssd.h
>> index 6d53647e..ad0d1d93 100644
>> --- a/utils/gssd/gssd.h
>> +++ b/utils/gssd/gssd.h
>> @@ -50,6 +50,11 @@
>> #define GSSD_DEFAULT_KEYTAB_FILE "/etc/krb5.keytab"
>> #define GSSD_SERVICE_NAME "nfs"
>> #define RPC_CHAN_BUF_SIZE 32768
>> +
> I think we should add a "/* seconds */"
> so you don't have dig in the code
> to see what interval is
>> +#define MIN_UPCALL_TIMEOUT 5
>> +#define DEF_UPCALL_TIMEOUT 30
>> +#define MAX_UPCALL_TIMEOUT 600
>> +
>> /*
>> * The gss mechanisms that we can handle
>> */
>> @@ -91,10 +96,20 @@ struct clnt_upcall_info {
>> char *service;
>> };
>>
>> +struct upcall_thread_info {
>> + TAILQ_ENTRY(upcall_thread_info) list;
>> + pthread_t tid;
>> + struct timespec timeout;
>> + uid_t uid;
>> + int fd;
>> + bool cancelled;
>> +};
>> +
>> void handle_krb5_upcall(struct clnt_info *clp);
>> void handle_gssd_upcall(struct clnt_info *clp);
>> void free_upcall_info(struct clnt_upcall_info *info);
>> void gssd_free_client(struct clnt_info *clp);
>> +int do_error_downcall(int k5_fd, uid_t uid, int err);
>>
>>
>> #endif /* _RPC_GSSD_H_ */
>> diff --git a/utils/gssd/gssd.man b/utils/gssd/gssd.man
>> index 9ae6def9..20fea729 100644
>> --- a/utils/gssd/gssd.man
>> +++ b/utils/gssd/gssd.man
>> @@ -8,7 +8,7 @@
>> rpc.gssd \- RPCSEC_GSS daemon
>> .SH SYNOPSIS
>> .B rpc.gssd
>> -.RB [ \-DfMnlvrH ]
>> +.RB [ \-DfMnlvrHC ]
>> .RB [ \-k
>> .IR keytab ]
>> .RB [ \-p
>> @@ -17,6 +17,10 @@ rpc.gssd \- RPCSEC_GSS daemon
>> .IR ccachedir ]
>> .RB [ \-t
>> .IR timeout ]
>> +.RB [ \-T
>> +.IR timeout ]
>> +.RB [ \-U
>> +.IR timeout ]
>> .RB [ \-R
>> .IR realm ]
>> .SH INTRODUCTION
>> @@ -275,7 +279,7 @@ seconds, which allows changing Kerberos tickets and identities frequently.
>> The default is no explicit timeout, which means the kernel context will live
>> the lifetime of the Kerberos service ticket used in its creation.
>> .TP
>> -.B -T timeout
>> +.BI "-T " timeout
>> Timeout, in seconds, to create an RPC connection with a server while
>> establishing an authenticated gss context for a user.
>> The default timeout is set to 5 seconds.
>> @@ -283,6 +287,18 @@ If you get messages like "WARNING: can't create tcp rpc_clnt to server
>> %servername% for user with uid %uid%: RPC: Remote system error -
>> Connection timed out", you should consider an increase of this timeout.
>> .TP
>> +.BI "-U " timeout
>> +Timeout, in seconds, for upcall threads. Threads executing longer than
>> +.I timeout
>> +seconds will be cancelled and an error of -ETIMEDOUT will be reported
>> +to the kernel. The default
>> +.I timeout
>> +is 30 seconds. The minimum is 5 seconds. The maximum is 600 seconds.
>> +.TP
>> +.B -C
>> +Instead of cancelling upcall threads that have timed out, cause an error
>> +message to be logged to the syslog (no error will be reported to the kernel).
>> +.TP
>> .B -H
>> Avoids setting $HOME to "/". This allows rpc.gssd to read per user k5identity
>> files versus trying to read /.k5identity for each user.
>> @@ -350,6 +366,17 @@ Equivalent to
>> Equivalent to
>> .BR -R .
>> .TP
>> +.B upcall-timeout
>> +Equivalent to
>> +.BR -U .
>> +.TP
>> +.B cancel-timed-out-upcalls
>> +Setting to
>> +.B false
>> +is equivalent to providing the
>> +.B -C
>> +flag.
>> +.TP
>> .B set-home
>> Setting to
>> .B false
>> diff --git a/utils/gssd/gssd_proc.c b/utils/gssd/gssd_proc.c
>> index ba508b30..ac7b1d1c 100644
>> --- a/utils/gssd/gssd_proc.c
>> +++ b/utils/gssd/gssd_proc.c
>> @@ -81,11 +81,23 @@
>> #include "gss_names.h"
>>
>> extern pthread_mutex_t clp_lock;
>> +extern pthread_mutex_t active_thread_list_lock;
>> +extern int upcall_timeout;
>> +extern TAILQ_HEAD(active_thread_list_head, upcall_thread_info) active_thread_list;
>>
>> /* Encryption types supported by the kernel rpcsec_gss code */
>> int num_krb5_enctypes = 0;
>> krb5_enctype *krb5_enctypes = NULL;
>>
>> +struct cleanup_args {
>> + OM_uint32 *min_stat;
>> + gss_buffer_t acceptor;
>> + gss_buffer_t token;
>> + struct authgss_private_data *pd;
>> + AUTH **auth;
>> + CLIENT **rpc_clnt;
>> +};
>> +
>> /*
>> * Parse the supported encryption type information
>> */
>> @@ -184,7 +196,7 @@ out_err:
>> return;
>> }
>>
>> -static int
>> +int
>> do_error_downcall(int k5_fd, uid_t uid, int err)
>> {
>> char buf[1024];
>> @@ -607,14 +619,37 @@ out:
>> return auth;
>> }
>>
>> +static void
>> +cleanup_handler(void *arg)
>> +{
>> + struct cleanup_args *args = (struct cleanup_args *)arg;
>> +
>> + gss_release_buffer(args->min_stat, args->acceptor);
>> + if (args->token->value)
>> + free(args->token->value);
>> +#ifdef HAVE_AUTHGSS_FREE_PRIVATE_DATA
>> + if (args->pd->pd_ctx_hndl.length != 0 || args->pd->pd_ctx != 0)
>> + authgss_free_private_data(args->pd);
>> +#endif
>> + if (*args->auth)
>> + AUTH_DESTROY(*args->auth);
>> + if (*args->rpc_clnt)
>> + clnt_destroy(*args->rpc_clnt);
>> +}
>> +
>> /*
>> * this code uses the userland rpcsec gss library to create a krb5
>> * context on behalf of the kernel
>> */
>> static void
>> -process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
>> - char *tgtname, char *service)
>> +process_krb5_upcall(struct clnt_upcall_info *info)
>> {
>> + struct clnt_info *clp = info->clp;
>> + uid_t uid = info->uid;
>> + int fd = info->fd;
>> + char *srchost = info->srchost;
>> + char *tgtname = info->target;
>> + char *service = info->service;
>> CLIENT *rpc_clnt = NULL;
>> AUTH *auth = NULL;
>> struct authgss_private_data pd;
>> @@ -624,11 +659,13 @@ process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
>> gss_name_t gacceptor = GSS_C_NO_NAME;
>> gss_OID mech;
>> gss_buffer_desc acceptor = {0};
>> + struct cleanup_args cleanup_args = {&min_stat, &acceptor, &token, &pd, &auth, &rpc_clnt};
>>
>> token.length = 0;
>> token.value = NULL;
>> memset(&pd, 0, sizeof(struct authgss_private_data));
>>
>> + pthread_cleanup_push(cleanup_handler, &cleanup_args);
>> /*
>> * If "service" is specified, then the kernel is indicating that
>> * we must use machine credentials for this request. (Regardless
>> @@ -650,6 +687,7 @@ process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
>> * used for this case is not important.
>> *
>> */
>> + pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);
>> if (uid != 0 || (uid == 0 && root_uses_machine_creds == 0 &&
>> service == NULL)) {
>>
>> @@ -670,15 +708,21 @@ process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
>> goto out_return_error;
>> }
>> }
>> + pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
>> + pthread_testcancel();
>>
>> + pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);
>> if (!authgss_get_private_data(auth, &pd)) {
>> printerr(1, "WARNING: Failed to obtain authentication "
>> "data for user with uid %d for server %s\n",
>> uid, clp->servername);
>> goto out_return_error;
>> }
>> + pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
>> + pthread_testcancel();
>>
>> /* Grab the context lifetime and acceptor name out of the ctx. */
>> + pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);
>> maj_stat = gss_inquire_context(&min_stat, pd.pd_ctx, NULL, &gacceptor,
>> &lifetime_rec, &mech, NULL, NULL, NULL);
>>
>> @@ -690,37 +734,35 @@ process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
>> get_hostbased_client_buffer(gacceptor, mech, &acceptor);
>> gss_release_name(&min_stat, &gacceptor);
>> }
>> + pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
>> + pthread_testcancel();
>>
>> /*
>> * The serialization can mean turning pd.pd_ctx into a lucid context. If
>> * that happens then the pd.pd_ctx will be unusable, so we must never
>> * try to use it after this point.
>> */
>> + pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);
>> if (serialize_context_for_kernel(&pd.pd_ctx, &token, &krb5oid, NULL)) {
>> printerr(1, "WARNING: Failed to serialize krb5 context for "
>> "user with uid %d for server %s\n",
>> uid, clp->servername);
>> goto out_return_error;
>> }
>> + pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
>> + pthread_testcancel();
>>
>> do_downcall(fd, uid, &pd, &token, lifetime_rec, &acceptor);
>>
>> out:
>> - gss_release_buffer(&min_stat, &acceptor);
>> - if (token.value)
>> - free(token.value);
>> -#ifdef HAVE_AUTHGSS_FREE_PRIVATE_DATA
>> - if (pd.pd_ctx_hndl.length != 0 || pd.pd_ctx != 0)
>> - authgss_free_private_data(&pd);
>> -#endif
>> - if (auth)
>> - AUTH_DESTROY(auth);
>> - if (rpc_clnt)
>> - clnt_destroy(rpc_clnt);
>> + pthread_cleanup_pop(1);
>>
>> return;
>>
>> out_return_error:
>> + pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
>> + pthread_testcancel();
>> +
>> do_error_downcall(fd, uid, downcall_err);
>> goto out;
>> }
>> @@ -786,38 +828,71 @@ void free_upcall_info(struct clnt_upcall_info *info)
>> }
>>
>> static void
>> -gssd_work_thread_fn(struct clnt_upcall_info *info)
>> +cleanup_clnt_upcall_info(void *arg)
>> {
>> - process_krb5_upcall(info->clp, info->uid, info->fd, info->srchost, info->target, info->service);
>> + struct clnt_upcall_info *info = (struct clnt_upcall_info *)arg;
>> +
>> free_upcall_info(info);
>> }
>>
>> +static void
>> +gssd_work_thread_fn(struct clnt_upcall_info *info)
>> +{
>> + pthread_cleanup_push(cleanup_clnt_upcall_info, info);
>> + process_krb5_upcall(info);
>> + pthread_cleanup_pop(1);
>> +}
>> +
>> +static struct upcall_thread_info *
>> +alloc_upcall_thread_info(void)
>> +{
>> + struct upcall_thread_info *info;
>> +
>> + info = malloc(sizeof(struct upcall_thread_info));
>> + if (info == NULL)
>> + return NULL;
>> + memset(info, 0, sizeof(*info));
>> + return info;
>> +}
>> +
>> static int
>> -start_upcall_thread(void (*func)(struct clnt_upcall_info *), void *info)
>> +start_upcall_thread(void (*func)(struct clnt_upcall_info *), struct clnt_upcall_info *info)
>> {
>> pthread_attr_t attr;
>> pthread_t th;
>> + struct upcall_thread_info *tinfo;
>> int ret;
>>
>> + tinfo = alloc_upcall_thread_info();
>> + if (!tinfo)
>> + return -ENOMEM;
>> + tinfo->fd = info->fd;
>> + tinfo->uid = info->uid;
>> + tinfo->cancelled = false;
>> +
>> ret = pthread_attr_init(&attr);
>> if (ret != 0) {
>> printerr(0, "ERROR: failed to init pthread attr: ret %d: %s\n",
>> ret, strerror(errno));
>> - return ret;
>> - }
>> - ret = pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED);
>> - if (ret != 0) {
>> - printerr(0, "ERROR: failed to create pthread attr: ret %d: "
>> - "%s\n", ret, strerror(errno));
>> + free(tinfo);
>> return ret;
>> }
>>
>> ret = pthread_create(&th, &attr, (void *)func, (void *)info);
>> - if (ret != 0)
>> + if (ret != 0) {
>> printerr(0, "ERROR: pthread_create failed: ret %d: %s\n",
>> ret, strerror(errno));
>> - else
>> - printerr(0, "created thread id 0x%lx\n", th);
>> + free(tinfo);
>> + return ret;
>> + }
>> + printerr(1, "created thread id 0x%lx\n", th);
> This will be removed...
>> + tinfo->tid = th;
>> + pthread_mutex_lock(&active_thread_list_lock);
>> + clock_gettime(CLOCK_MONOTONIC, &tinfo->timeout);
>> + tinfo->timeout.tv_sec += upcall_timeout;
>> + TAILQ_INSERT_TAIL(&active_thread_list, tinfo, list);
>> + pthread_mutex_unlock(&active_thread_list_lock);
>> +
>> return ret;
>> }
>>
>>
>
> Overall I think the code is very well written with
> one exception... The lack of comments. I think it
> would be very useful to let the reader know what
> you are doing and why.... But by no means is
> that a show stopper. Nice work!
>
> I'm still doing more testing and nothing
> is breaking... So it is looking pretty good!
>
> steved.
>

--
Chuck Lever



2021-05-27 11:42:41

by Scott Mayhew

[permalink] [raw]
Subject: Re: [nfs-utils RFC PATCH 2/2] gssd: add timeout for upcall threads

On Wed, 26 May 2021, Steve Dickson wrote:

> Hey!
>
> Again... a few very small teaks
>
> On 5/25/21 2:00 PM, Scott Mayhew wrote:
> > Add a global list of active upcalls and a watchdog thread that walks the
> > list, looking for threads running longer than timeout seconds. By
> > default, the watchdog thread will cancel these threads and report an
> > error of -ETIMEDOUT to the kernel. Passing the -C option or setting
> > cancel-timed-out-upcalls=0 in nfs.conf disables this behavior and
> > causes the watchdog thread to simply log an error message instead. The
> > upcall timeout can be specified by passing the -U option or by setting
> > the upcall-timeout parameter in nfs.conf.
> >
> > Signed-off-by: Scott Mayhew <[email protected]>
> > ---
> > nfs.conf | 2 +
> > utils/gssd/gssd.c | 125 +++++++++++++++++++++++++++++++++++++++-
> > utils/gssd/gssd.h | 15 +++++
> > utils/gssd/gssd.man | 31 +++++++++-
> > utils/gssd/gssd_proc.c | 127 ++++++++++++++++++++++++++++++++---------
> > 5 files changed, 270 insertions(+), 30 deletions(-)
> >
> > diff --git a/nfs.conf b/nfs.conf
> > index 31994f61..7a987788 100644
> > --- a/nfs.conf
> > +++ b/nfs.conf
> > @@ -25,6 +25,8 @@
> > # cred-cache-directory=
> > # preferred-realm=
> > # set-home=1
> > +# upcall-timeout=30
> > +# cancel-timed-out-upcalls=1
> > #
> > [lockd]
> > # port=0
> > diff --git a/utils/gssd/gssd.c b/utils/gssd/gssd.c
> > index eb440470..54a1ea3f 100644
> > --- a/utils/gssd/gssd.c
> > +++ b/utils/gssd/gssd.c
> > @@ -95,9 +95,15 @@ static bool use_gssproxy = false;
> > pthread_mutex_t clp_lock = PTHREAD_MUTEX_INITIALIZER;
> > static bool signal_received = false;
> > static struct event_base *evbase = NULL;
> > +pthread_mutex_t active_thread_list_lock = PTHREAD_MUTEX_INITIALIZER;
> > +
> > +int upcall_timeout = DEF_UPCALL_TIMEOUT;
> > +static bool cancel_timed_out_upcalls = true;
> >
> > TAILQ_HEAD(topdir_list_head, topdir) topdir_list;
> >
> > +TAILQ_HEAD(active_thread_list_head, upcall_thread_info) active_thread_list;
> > +
> > struct topdir {
> > TAILQ_ENTRY(topdir) list;
> > TAILQ_HEAD(clnt_list_head, clnt_info) clnt_list;
> > @@ -436,6 +442,100 @@ gssd_clnt_krb5_cb(int UNUSED(fd), short UNUSED(which), void *data)
> > handle_krb5_upcall(clp);
> > }
> >
> > +static int
> > +scan_active_thread_list(void)
> > +{
> > + struct upcall_thread_info *info;
> > + struct timespec now;
> > + unsigned int sleeptime;
> > + bool sleeptime_set = false;
> > + int err;
> > + void *tret, *saveprev;
> > +
> > + sleeptime = upcall_timeout;
> > + pthread_mutex_lock(&active_thread_list_lock);
> > + clock_gettime(CLOCK_MONOTONIC, &now);
> > + TAILQ_FOREACH(info, &active_thread_list, list) {
> > + err = pthread_tryjoin_np(info->tid, &tret);
> > + switch (err) {
> > + case 0:
> > + if (tret == PTHREAD_CANCELED)
> > + printerr(3, "watchdog: thread id 0x%lx cancelled successfully\n",
> > + info->tid);
> > + saveprev = info->list.tqe_prev;
> > + TAILQ_REMOVE(&active_thread_list, info, list);
> > + free(info);
> > + info = saveprev;
> > + break;
> > + case EBUSY:
> > + if (now.tv_sec >= info->timeout.tv_sec) {
> > + if (cancel_timed_out_upcalls && !info->cancelled) {
> > + printerr(0, "watchdog: thread id 0x%lx timed out\n",
> > + info->tid);
> > + pthread_cancel(info->tid);
> > + info->cancelled = true;
> > + do_error_downcall(info->fd, info->uid, -ETIMEDOUT);
> > + } else {
> > + printerr(0, "watchdog: thread id 0x%lx running for %ld seconds\n",
> > + info->tid,
> > + now.tv_sec - info->timeout.tv_sec + upcall_timeout);
> If people are going to used the -C flag they are saying they want
> to ignore hung threads so I'm thinking with printerr(0) we would
> be filling up their logs about messages they don't care about.
> So I'm thinking we should change this to a printerr(1)

Note that message could pop multiple times per thread even without the
-C flag because cancellation isn't immediate (a thread needs to hit a
cancellation point, which it won't actually do that until it comes back
from wherever it's hanging). My thinking was leaving it with
printerr(0) would make it blatantly obvious when something was wrong and
needed to be investigated. I have no issue with changing it to
printerr(1) though.

Alternatively we could add another flag to struct upcall_thread_info to
ensure that message only gets logged once per thread.

>
> > + }
> > + } else if (!sleeptime_set) {
> > + sleeptime = info->timeout.tv_sec - now.tv_sec;
> > + sleeptime_set = true;
> > + }
> > + break;
> > + default:
> > + printerr(0, "watchdog: attempt to join thread id 0x%lx returned %d (%s)!\n",
> > + info->tid, err, strerror(err));
> > + break;
> > + }
> > + }
> > + pthread_mutex_unlock(&active_thread_list_lock);
> > +
> > + return sleeptime;
> > +}
> > +
> > +static void *
> > +watchdog_thread_fn(void *UNUSED(arg))
> > +{
> > + unsigned int sleeptime;
> > +
> > + for (;;) {
> > + sleeptime = scan_active_thread_list();
> > + printerr(4, "watchdog: sleeping %u secs\n", sleeptime);
> > + sleep(sleeptime);
> > + }
> > + return (void *)0;
> > +}
> > +
> > +static int
> > +start_watchdog_thread(void)
> > +{
> > + pthread_attr_t attr;
> > + pthread_t th;
> > + int ret;
> > +
> > + ret = pthread_attr_init(&attr);
> > + if (ret != 0) {
> > + printerr(0, "ERROR: failed to init pthread attr: ret %d: %s\n",
> > + ret, strerror(errno));
> > + return ret;
> > + }
> > + ret = pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED);
> > + if (ret != 0) {
> > + printerr(0, "ERROR: failed to create pthread attr: ret %d: %s\n",
> > + ret, strerror(errno));
> > + return ret;
> > + }
> > + ret = pthread_create(&th, &attr, watchdog_thread_fn, NULL);
> > + if (ret != 0) {
> > + printerr(0, "ERROR: pthread_create failed: ret %d: %s\n",
> > + ret, strerror(errno));
> > + }
> > + return ret;
> > +}
> > +
> > static struct clnt_info *
> > gssd_get_clnt(struct topdir *tdi, const char *name)
> > {
> > @@ -825,7 +925,7 @@ sig_die(int signal)
> > static void
> > usage(char *progname)
> > {
> > - fprintf(stderr, "usage: %s [-f] [-l] [-M] [-n] [-v] [-r] [-p pipefsdir] [-k keytab] [-d ccachedir] [-t timeout] [-R preferred realm] [-D] [-H]\n",
> > + fprintf(stderr, "usage: %s [-f] [-l] [-M] [-n] [-v] [-r] [-p pipefsdir] [-k keytab] [-d ccachedir] [-t timeout] [-R preferred realm] [-D] [-H] [-U upcall timeout] [-C]\n",
> > progname);
> > exit(1);
> > }
> > @@ -846,6 +946,9 @@ read_gss_conf(void)
> > #endif
> > context_timeout = conf_get_num("gssd", "context-timeout", context_timeout);
> > rpc_timeout = conf_get_num("gssd", "rpc-timeout", rpc_timeout);
> > + upcall_timeout = conf_get_num("gssd", "upcall-timeout", upcall_timeout);
> > + cancel_timed_out_upcalls = conf_get_bool("gssd", "cancel-timed-out-upcalls",
> > + cancel_timed_out_upcalls);
> > s = conf_get_str("gssd", "pipefs-directory");
> > if (!s)
> > s = conf_get_str("general", "pipefs-directory");
> > @@ -887,7 +990,7 @@ main(int argc, char *argv[])
> > verbosity = conf_get_num("gssd", "verbosity", verbosity);
> > rpc_verbosity = conf_get_num("gssd", "rpc-verbosity", rpc_verbosity);
> >
> > - while ((opt = getopt(argc, argv, "HDfvrlmnMp:k:d:t:T:R:")) != -1) {
> > + while ((opt = getopt(argc, argv, "HDfvrlmnMp:k:d:t:T:R:U:C")) != -1) {
> > switch (opt) {
> > case 'f':
> > fg = 1;
> > @@ -938,6 +1041,11 @@ main(int argc, char *argv[])
> > case 'H':
> > set_home = false;
> > break;
> > + case 'U':
> > + upcall_timeout = atoi(optarg);
> > + break;
> > + case 'C':
> > + cancel_timed_out_upcalls = false;
> > default:
> > usage(argv[0]);
> > break;
> > @@ -1010,6 +1118,11 @@ main(int argc, char *argv[])
> > else
> > progname = argv[0];
> >
> > + if (upcall_timeout > MAX_UPCALL_TIMEOUT)
> > + upcall_timeout = MAX_UPCALL_TIMEOUT;
> > + else if (upcall_timeout < MIN_UPCALL_TIMEOUT)
> > + upcall_timeout = MIN_UPCALL_TIMEOUT;
> > +
> > initerr(progname, verbosity, fg);
> > #ifdef HAVE_LIBTIRPC_SET_DEBUG
> > /*
> > @@ -1068,6 +1181,14 @@ main(int argc, char *argv[])
> > }
> > event_add(inotify_ev, NULL);
> >
> > + TAILQ_INIT(&active_thread_list);
> > +
> > + rc = start_watchdog_thread();
> > + if (rc != 0) {
> > + printerr(0, "ERROR: failed to start watchdog thread: %d\n", rc);
> > + exit(EXIT_FAILURE);
> > + }
> > +
> > TAILQ_INIT(&topdir_list);
> > gssd_scan();
> > daemon_ready();
> > diff --git a/utils/gssd/gssd.h b/utils/gssd/gssd.h
> > index 6d53647e..ad0d1d93 100644
> > --- a/utils/gssd/gssd.h
> > +++ b/utils/gssd/gssd.h
> > @@ -50,6 +50,11 @@
> > #define GSSD_DEFAULT_KEYTAB_FILE "/etc/krb5.keytab"
> > #define GSSD_SERVICE_NAME "nfs"
> > #define RPC_CHAN_BUF_SIZE 32768
> > +
> I think we should add a "/* seconds */"
> so you don't have dig in the code
> to see what interval is
> > +#define MIN_UPCALL_TIMEOUT 5
> > +#define DEF_UPCALL_TIMEOUT 30
> > +#define MAX_UPCALL_TIMEOUT 600
> > +
> > /*
> > * The gss mechanisms that we can handle
> > */
> > @@ -91,10 +96,20 @@ struct clnt_upcall_info {
> > char *service;
> > };
> >
> > +struct upcall_thread_info {
> > + TAILQ_ENTRY(upcall_thread_info) list;
> > + pthread_t tid;
> > + struct timespec timeout;
> > + uid_t uid;
> > + int fd;
> > + bool cancelled;
> > +};
> > +
> > void handle_krb5_upcall(struct clnt_info *clp);
> > void handle_gssd_upcall(struct clnt_info *clp);
> > void free_upcall_info(struct clnt_upcall_info *info);
> > void gssd_free_client(struct clnt_info *clp);
> > +int do_error_downcall(int k5_fd, uid_t uid, int err);
> >
> >
> > #endif /* _RPC_GSSD_H_ */
> > diff --git a/utils/gssd/gssd.man b/utils/gssd/gssd.man
> > index 9ae6def9..20fea729 100644
> > --- a/utils/gssd/gssd.man
> > +++ b/utils/gssd/gssd.man
> > @@ -8,7 +8,7 @@
> > rpc.gssd \- RPCSEC_GSS daemon
> > .SH SYNOPSIS
> > .B rpc.gssd
> > -.RB [ \-DfMnlvrH ]
> > +.RB [ \-DfMnlvrHC ]
> > .RB [ \-k
> > .IR keytab ]
> > .RB [ \-p
> > @@ -17,6 +17,10 @@ rpc.gssd \- RPCSEC_GSS daemon
> > .IR ccachedir ]
> > .RB [ \-t
> > .IR timeout ]
> > +.RB [ \-T
> > +.IR timeout ]
> > +.RB [ \-U
> > +.IR timeout ]
> > .RB [ \-R
> > .IR realm ]
> > .SH INTRODUCTION
> > @@ -275,7 +279,7 @@ seconds, which allows changing Kerberos tickets and identities frequently.
> > The default is no explicit timeout, which means the kernel context will live
> > the lifetime of the Kerberos service ticket used in its creation.
> > .TP
> > -.B -T timeout
> > +.BI "-T " timeout
> > Timeout, in seconds, to create an RPC connection with a server while
> > establishing an authenticated gss context for a user.
> > The default timeout is set to 5 seconds.
> > @@ -283,6 +287,18 @@ If you get messages like "WARNING: can't create tcp rpc_clnt to server
> > %servername% for user with uid %uid%: RPC: Remote system error -
> > Connection timed out", you should consider an increase of this timeout.
> > .TP
> > +.BI "-U " timeout
> > +Timeout, in seconds, for upcall threads. Threads executing longer than
> > +.I timeout
> > +seconds will be cancelled and an error of -ETIMEDOUT will be reported
> > +to the kernel. The default
> > +.I timeout
> > +is 30 seconds. The minimum is 5 seconds. The maximum is 600 seconds.
> > +.TP
> > +.B -C
> > +Instead of cancelling upcall threads that have timed out, cause an error
> > +message to be logged to the syslog (no error will be reported to the kernel).
> > +.TP
> > .B -H
> > Avoids setting $HOME to "/". This allows rpc.gssd to read per user k5identity
> > files versus trying to read /.k5identity for each user.
> > @@ -350,6 +366,17 @@ Equivalent to
> > Equivalent to
> > .BR -R .
> > .TP
> > +.B upcall-timeout
> > +Equivalent to
> > +.BR -U .
> > +.TP
> > +.B cancel-timed-out-upcalls
> > +Setting to
> > +.B false
> > +is equivalent to providing the
> > +.B -C
> > +flag.
> > +.TP
> > .B set-home
> > Setting to
> > .B false
> > diff --git a/utils/gssd/gssd_proc.c b/utils/gssd/gssd_proc.c
> > index ba508b30..ac7b1d1c 100644
> > --- a/utils/gssd/gssd_proc.c
> > +++ b/utils/gssd/gssd_proc.c
> > @@ -81,11 +81,23 @@
> > #include "gss_names.h"
> >
> > extern pthread_mutex_t clp_lock;
> > +extern pthread_mutex_t active_thread_list_lock;
> > +extern int upcall_timeout;
> > +extern TAILQ_HEAD(active_thread_list_head, upcall_thread_info) active_thread_list;
> >
> > /* Encryption types supported by the kernel rpcsec_gss code */
> > int num_krb5_enctypes = 0;
> > krb5_enctype *krb5_enctypes = NULL;
> >
> > +struct cleanup_args {
> > + OM_uint32 *min_stat;
> > + gss_buffer_t acceptor;
> > + gss_buffer_t token;
> > + struct authgss_private_data *pd;
> > + AUTH **auth;
> > + CLIENT **rpc_clnt;
> > +};
> > +
> > /*
> > * Parse the supported encryption type information
> > */
> > @@ -184,7 +196,7 @@ out_err:
> > return;
> > }
> >
> > -static int
> > +int
> > do_error_downcall(int k5_fd, uid_t uid, int err)
> > {
> > char buf[1024];
> > @@ -607,14 +619,37 @@ out:
> > return auth;
> > }
> >
> > +static void
> > +cleanup_handler(void *arg)
> > +{
> > + struct cleanup_args *args = (struct cleanup_args *)arg;
> > +
> > + gss_release_buffer(args->min_stat, args->acceptor);
> > + if (args->token->value)
> > + free(args->token->value);
> > +#ifdef HAVE_AUTHGSS_FREE_PRIVATE_DATA
> > + if (args->pd->pd_ctx_hndl.length != 0 || args->pd->pd_ctx != 0)
> > + authgss_free_private_data(args->pd);
> > +#endif
> > + if (*args->auth)
> > + AUTH_DESTROY(*args->auth);
> > + if (*args->rpc_clnt)
> > + clnt_destroy(*args->rpc_clnt);
> > +}
> > +
> > /*
> > * this code uses the userland rpcsec gss library to create a krb5
> > * context on behalf of the kernel
> > */
> > static void
> > -process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
> > - char *tgtname, char *service)
> > +process_krb5_upcall(struct clnt_upcall_info *info)
> > {
> > + struct clnt_info *clp = info->clp;
> > + uid_t uid = info->uid;
> > + int fd = info->fd;
> > + char *srchost = info->srchost;
> > + char *tgtname = info->target;
> > + char *service = info->service;
> > CLIENT *rpc_clnt = NULL;
> > AUTH *auth = NULL;
> > struct authgss_private_data pd;
> > @@ -624,11 +659,13 @@ process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
> > gss_name_t gacceptor = GSS_C_NO_NAME;
> > gss_OID mech;
> > gss_buffer_desc acceptor = {0};
> > + struct cleanup_args cleanup_args = {&min_stat, &acceptor, &token, &pd, &auth, &rpc_clnt};
> >
> > token.length = 0;
> > token.value = NULL;
> > memset(&pd, 0, sizeof(struct authgss_private_data));
> >
> > + pthread_cleanup_push(cleanup_handler, &cleanup_args);
> > /*
> > * If "service" is specified, then the kernel is indicating that
> > * we must use machine credentials for this request. (Regardless
> > @@ -650,6 +687,7 @@ process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
> > * used for this case is not important.
> > *
> > */
> > + pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);
> > if (uid != 0 || (uid == 0 && root_uses_machine_creds == 0 &&
> > service == NULL)) {
> >
> > @@ -670,15 +708,21 @@ process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
> > goto out_return_error;
> > }
> > }
> > + pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
> > + pthread_testcancel();
> >
> > + pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);
> > if (!authgss_get_private_data(auth, &pd)) {
> > printerr(1, "WARNING: Failed to obtain authentication "
> > "data for user with uid %d for server %s\n",
> > uid, clp->servername);
> > goto out_return_error;
> > }
> > + pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
> > + pthread_testcancel();
> >
> > /* Grab the context lifetime and acceptor name out of the ctx. */
> > + pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);
> > maj_stat = gss_inquire_context(&min_stat, pd.pd_ctx, NULL, &gacceptor,
> > &lifetime_rec, &mech, NULL, NULL, NULL);
> >
> > @@ -690,37 +734,35 @@ process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
> > get_hostbased_client_buffer(gacceptor, mech, &acceptor);
> > gss_release_name(&min_stat, &gacceptor);
> > }
> > + pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
> > + pthread_testcancel();
> >
> > /*
> > * The serialization can mean turning pd.pd_ctx into a lucid context. If
> > * that happens then the pd.pd_ctx will be unusable, so we must never
> > * try to use it after this point.
> > */
> > + pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);
> > if (serialize_context_for_kernel(&pd.pd_ctx, &token, &krb5oid, NULL)) {
> > printerr(1, "WARNING: Failed to serialize krb5 context for "
> > "user with uid %d for server %s\n",
> > uid, clp->servername);
> > goto out_return_error;
> > }
> > + pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
> > + pthread_testcancel();
> >
> > do_downcall(fd, uid, &pd, &token, lifetime_rec, &acceptor);
> >
> > out:
> > - gss_release_buffer(&min_stat, &acceptor);
> > - if (token.value)
> > - free(token.value);
> > -#ifdef HAVE_AUTHGSS_FREE_PRIVATE_DATA
> > - if (pd.pd_ctx_hndl.length != 0 || pd.pd_ctx != 0)
> > - authgss_free_private_data(&pd);
> > -#endif
> > - if (auth)
> > - AUTH_DESTROY(auth);
> > - if (rpc_clnt)
> > - clnt_destroy(rpc_clnt);
> > + pthread_cleanup_pop(1);
> >
> > return;
> >
> > out_return_error:
> > + pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
> > + pthread_testcancel();
> > +
> > do_error_downcall(fd, uid, downcall_err);
> > goto out;
> > }
> > @@ -786,38 +828,71 @@ void free_upcall_info(struct clnt_upcall_info *info)
> > }
> >
> > static void
> > -gssd_work_thread_fn(struct clnt_upcall_info *info)
> > +cleanup_clnt_upcall_info(void *arg)
> > {
> > - process_krb5_upcall(info->clp, info->uid, info->fd, info->srchost, info->target, info->service);
> > + struct clnt_upcall_info *info = (struct clnt_upcall_info *)arg;
> > +
> > free_upcall_info(info);
> > }
> >
> > +static void
> > +gssd_work_thread_fn(struct clnt_upcall_info *info)
> > +{
> > + pthread_cleanup_push(cleanup_clnt_upcall_info, info);
> > + process_krb5_upcall(info);
> > + pthread_cleanup_pop(1);
> > +}
> > +
> > +static struct upcall_thread_info *
> > +alloc_upcall_thread_info(void)
> > +{
> > + struct upcall_thread_info *info;
> > +
> > + info = malloc(sizeof(struct upcall_thread_info));
> > + if (info == NULL)
> > + return NULL;
> > + memset(info, 0, sizeof(*info));
> > + return info;
> > +}
> > +
> > static int
> > -start_upcall_thread(void (*func)(struct clnt_upcall_info *), void *info)
> > +start_upcall_thread(void (*func)(struct clnt_upcall_info *), struct clnt_upcall_info *info)
> > {
> > pthread_attr_t attr;
> > pthread_t th;
> > + struct upcall_thread_info *tinfo;
> > int ret;
> >
> > + tinfo = alloc_upcall_thread_info();
> > + if (!tinfo)
> > + return -ENOMEM;
> > + tinfo->fd = info->fd;
> > + tinfo->uid = info->uid;
> > + tinfo->cancelled = false;
> > +
> > ret = pthread_attr_init(&attr);
> > if (ret != 0) {
> > printerr(0, "ERROR: failed to init pthread attr: ret %d: %s\n",
> > ret, strerror(errno));
> > - return ret;
> > - }
> > - ret = pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED);
> > - if (ret != 0) {
> > - printerr(0, "ERROR: failed to create pthread attr: ret %d: "
> > - "%s\n", ret, strerror(errno));
> > + free(tinfo);
> > return ret;
> > }
> >
> > ret = pthread_create(&th, &attr, (void *)func, (void *)info);
> > - if (ret != 0)
> > + if (ret != 0) {
> > printerr(0, "ERROR: pthread_create failed: ret %d: %s\n",
> > ret, strerror(errno));
> > - else
> > - printerr(0, "created thread id 0x%lx\n", th);
> > + free(tinfo);
> > + return ret;
> > + }
> > + printerr(1, "created thread id 0x%lx\n", th);
> This will be removed...
> > + tinfo->tid = th;
> > + pthread_mutex_lock(&active_thread_list_lock);
> > + clock_gettime(CLOCK_MONOTONIC, &tinfo->timeout);
> > + tinfo->timeout.tv_sec += upcall_timeout;
> > + TAILQ_INSERT_TAIL(&active_thread_list, tinfo, list);
> > + pthread_mutex_unlock(&active_thread_list_lock);
> > +
> > return ret;
> > }
> >
> >
>
> Overall I think the code is very well written with
> one exception... The lack of comments. I think it
> would be very useful to let the reader know what
> you are doing and why.... But by no means is
> that a show stopper. Nice work!

I can go back and add some comments.

-Scott
>
> I'm still doing more testing and nothing
> is breaking... So it is looking pretty good!
>
> steved.
>

2021-05-27 12:03:18

by Scott Mayhew

[permalink] [raw]
Subject: Re: [nfs-utils RFC PATCH 2/2] gssd: add timeout for upcall threads

On Wed, 26 May 2021, Chuck Lever III wrote:

> Hi Scott-
>
>
> > On May 26, 2021, at 1:08 PM, Steve Dickson <[email protected]> wrote:
> >
> > Hey!
> >
> > Again... a few very small teaks
> >
> > On 5/25/21 2:00 PM, Scott Mayhew wrote:
> >> Add a global list of active upcalls and a watchdog thread that walks the
> >> list, looking for threads running longer than timeout seconds. By
> >> default, the watchdog thread will cancel these threads and report an
> >> error of -ETIMEDOUT to the kernel. Passing the -C option or setting
> >> cancel-timed-out-upcalls=0 in nfs.conf disables this behavior and
> >> causes the watchdog thread to simply log an error message instead. The
> >> upcall timeout can be specified by passing the -U option or by setting
> >> the upcall-timeout parameter in nfs.conf.
>
> Not a critique of this patch, but I'm wondering if there's any
> way to get a sense of why each stuck thread was hung so we (or
> the local admin) can understand the underlying problems. Maybe
> that's something for another day.

I had planned on doing that originally, but most of the actual
interesting stuff happens in libtirpc, libgssapi_krb5, etc.

Plus, it took a bit longer than I thought it would just to get this
patch working... so yes, maybe another day :)

-Scott

>
>
> >> Signed-off-by: Scott Mayhew <[email protected]>
> >> ---
> >> nfs.conf | 2 +
> >> utils/gssd/gssd.c | 125 +++++++++++++++++++++++++++++++++++++++-
> >> utils/gssd/gssd.h | 15 +++++
> >> utils/gssd/gssd.man | 31 +++++++++-
> >> utils/gssd/gssd_proc.c | 127 ++++++++++++++++++++++++++++++++---------
> >> 5 files changed, 270 insertions(+), 30 deletions(-)
> >>
> >> diff --git a/nfs.conf b/nfs.conf
> >> index 31994f61..7a987788 100644
> >> --- a/nfs.conf
> >> +++ b/nfs.conf
> >> @@ -25,6 +25,8 @@
> >> # cred-cache-directory=
> >> # preferred-realm=
> >> # set-home=1
> >> +# upcall-timeout=30
> >> +# cancel-timed-out-upcalls=1
> >> #
> >> [lockd]
> >> # port=0
> >> diff --git a/utils/gssd/gssd.c b/utils/gssd/gssd.c
> >> index eb440470..54a1ea3f 100644
> >> --- a/utils/gssd/gssd.c
> >> +++ b/utils/gssd/gssd.c
> >> @@ -95,9 +95,15 @@ static bool use_gssproxy = false;
> >> pthread_mutex_t clp_lock = PTHREAD_MUTEX_INITIALIZER;
> >> static bool signal_received = false;
> >> static struct event_base *evbase = NULL;
> >> +pthread_mutex_t active_thread_list_lock = PTHREAD_MUTEX_INITIALIZER;
> >> +
> >> +int upcall_timeout = DEF_UPCALL_TIMEOUT;
> >> +static bool cancel_timed_out_upcalls = true;
> >>
> >> TAILQ_HEAD(topdir_list_head, topdir) topdir_list;
> >>
> >> +TAILQ_HEAD(active_thread_list_head, upcall_thread_info) active_thread_list;
> >> +
> >> struct topdir {
> >> TAILQ_ENTRY(topdir) list;
> >> TAILQ_HEAD(clnt_list_head, clnt_info) clnt_list;
> >> @@ -436,6 +442,100 @@ gssd_clnt_krb5_cb(int UNUSED(fd), short UNUSED(which), void *data)
> >> handle_krb5_upcall(clp);
> >> }
> >>
> >> +static int
> >> +scan_active_thread_list(void)
> >> +{
> >> + struct upcall_thread_info *info;
> >> + struct timespec now;
> >> + unsigned int sleeptime;
> >> + bool sleeptime_set = false;
> >> + int err;
> >> + void *tret, *saveprev;
> >> +
> >> + sleeptime = upcall_timeout;
> >> + pthread_mutex_lock(&active_thread_list_lock);
> >> + clock_gettime(CLOCK_MONOTONIC, &now);
> >> + TAILQ_FOREACH(info, &active_thread_list, list) {
> >> + err = pthread_tryjoin_np(info->tid, &tret);
> >> + switch (err) {
> >> + case 0:
> >> + if (tret == PTHREAD_CANCELED)
> >> + printerr(3, "watchdog: thread id 0x%lx cancelled successfully\n",
> >> + info->tid);
> >> + saveprev = info->list.tqe_prev;
> >> + TAILQ_REMOVE(&active_thread_list, info, list);
> >> + free(info);
> >> + info = saveprev;
> >> + break;
> >> + case EBUSY:
> >> + if (now.tv_sec >= info->timeout.tv_sec) {
> >> + if (cancel_timed_out_upcalls && !info->cancelled) {
> >> + printerr(0, "watchdog: thread id 0x%lx timed out\n",
> >> + info->tid);
> >> + pthread_cancel(info->tid);
> >> + info->cancelled = true;
> >> + do_error_downcall(info->fd, info->uid, -ETIMEDOUT);
> >> + } else {
> >> + printerr(0, "watchdog: thread id 0x%lx running for %ld seconds\n",
> >> + info->tid,
> >> + now.tv_sec - info->timeout.tv_sec + upcall_timeout);
> > If people are going to used the -C flag they are saying they want
> > to ignore hung threads so I'm thinking with printerr(0) we would
> > be filling up their logs about messages they don't care about.
> > So I'm thinking we should change this to a printerr(1)
> >
> >> + }
> >> + } else if (!sleeptime_set) {
> >> + sleeptime = info->timeout.tv_sec - now.tv_sec;
> >> + sleeptime_set = true;
> >> + }
> >> + break;
> >> + default:
> >> + printerr(0, "watchdog: attempt to join thread id 0x%lx returned %d (%s)!\n",
> >> + info->tid, err, strerror(err));
> >> + break;
> >> + }
> >> + }
> >> + pthread_mutex_unlock(&active_thread_list_lock);
> >> +
> >> + return sleeptime;
> >> +}
> >> +
> >> +static void *
> >> +watchdog_thread_fn(void *UNUSED(arg))
> >> +{
> >> + unsigned int sleeptime;
> >> +
> >> + for (;;) {
> >> + sleeptime = scan_active_thread_list();
> >> + printerr(4, "watchdog: sleeping %u secs\n", sleeptime);
> >> + sleep(sleeptime);
> >> + }
> >> + return (void *)0;
> >> +}
> >> +
> >> +static int
> >> +start_watchdog_thread(void)
> >> +{
> >> + pthread_attr_t attr;
> >> + pthread_t th;
> >> + int ret;
> >> +
> >> + ret = pthread_attr_init(&attr);
> >> + if (ret != 0) {
> >> + printerr(0, "ERROR: failed to init pthread attr: ret %d: %s\n",
> >> + ret, strerror(errno));
> >> + return ret;
> >> + }
> >> + ret = pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED);
> >> + if (ret != 0) {
> >> + printerr(0, "ERROR: failed to create pthread attr: ret %d: %s\n",
> >> + ret, strerror(errno));
> >> + return ret;
> >> + }
> >> + ret = pthread_create(&th, &attr, watchdog_thread_fn, NULL);
> >> + if (ret != 0) {
> >> + printerr(0, "ERROR: pthread_create failed: ret %d: %s\n",
> >> + ret, strerror(errno));
> >> + }
> >> + return ret;
> >> +}
> >> +
> >> static struct clnt_info *
> >> gssd_get_clnt(struct topdir *tdi, const char *name)
> >> {
> >> @@ -825,7 +925,7 @@ sig_die(int signal)
> >> static void
> >> usage(char *progname)
> >> {
> >> - fprintf(stderr, "usage: %s [-f] [-l] [-M] [-n] [-v] [-r] [-p pipefsdir] [-k keytab] [-d ccachedir] [-t timeout] [-R preferred realm] [-D] [-H]\n",
> >> + fprintf(stderr, "usage: %s [-f] [-l] [-M] [-n] [-v] [-r] [-p pipefsdir] [-k keytab] [-d ccachedir] [-t timeout] [-R preferred realm] [-D] [-H] [-U upcall timeout] [-C]\n",
> >> progname);
> >> exit(1);
> >> }
> >> @@ -846,6 +946,9 @@ read_gss_conf(void)
> >> #endif
> >> context_timeout = conf_get_num("gssd", "context-timeout", context_timeout);
> >> rpc_timeout = conf_get_num("gssd", "rpc-timeout", rpc_timeout);
> >> + upcall_timeout = conf_get_num("gssd", "upcall-timeout", upcall_timeout);
> >> + cancel_timed_out_upcalls = conf_get_bool("gssd", "cancel-timed-out-upcalls",
> >> + cancel_timed_out_upcalls);
> >> s = conf_get_str("gssd", "pipefs-directory");
> >> if (!s)
> >> s = conf_get_str("general", "pipefs-directory");
> >> @@ -887,7 +990,7 @@ main(int argc, char *argv[])
> >> verbosity = conf_get_num("gssd", "verbosity", verbosity);
> >> rpc_verbosity = conf_get_num("gssd", "rpc-verbosity", rpc_verbosity);
> >>
> >> - while ((opt = getopt(argc, argv, "HDfvrlmnMp:k:d:t:T:R:")) != -1) {
> >> + while ((opt = getopt(argc, argv, "HDfvrlmnMp:k:d:t:T:R:U:C")) != -1) {
> >> switch (opt) {
> >> case 'f':
> >> fg = 1;
> >> @@ -938,6 +1041,11 @@ main(int argc, char *argv[])
> >> case 'H':
> >> set_home = false;
> >> break;
> >> + case 'U':
> >> + upcall_timeout = atoi(optarg);
> >> + break;
> >> + case 'C':
> >> + cancel_timed_out_upcalls = false;
> >> default:
> >> usage(argv[0]);
> >> break;
> >> @@ -1010,6 +1118,11 @@ main(int argc, char *argv[])
> >> else
> >> progname = argv[0];
> >>
> >> + if (upcall_timeout > MAX_UPCALL_TIMEOUT)
> >> + upcall_timeout = MAX_UPCALL_TIMEOUT;
> >> + else if (upcall_timeout < MIN_UPCALL_TIMEOUT)
> >> + upcall_timeout = MIN_UPCALL_TIMEOUT;
> >> +
> >> initerr(progname, verbosity, fg);
> >> #ifdef HAVE_LIBTIRPC_SET_DEBUG
> >> /*
> >> @@ -1068,6 +1181,14 @@ main(int argc, char *argv[])
> >> }
> >> event_add(inotify_ev, NULL);
> >>
> >> + TAILQ_INIT(&active_thread_list);
> >> +
> >> + rc = start_watchdog_thread();
> >> + if (rc != 0) {
> >> + printerr(0, "ERROR: failed to start watchdog thread: %d\n", rc);
> >> + exit(EXIT_FAILURE);
> >> + }
> >> +
> >> TAILQ_INIT(&topdir_list);
> >> gssd_scan();
> >> daemon_ready();
> >> diff --git a/utils/gssd/gssd.h b/utils/gssd/gssd.h
> >> index 6d53647e..ad0d1d93 100644
> >> --- a/utils/gssd/gssd.h
> >> +++ b/utils/gssd/gssd.h
> >> @@ -50,6 +50,11 @@
> >> #define GSSD_DEFAULT_KEYTAB_FILE "/etc/krb5.keytab"
> >> #define GSSD_SERVICE_NAME "nfs"
> >> #define RPC_CHAN_BUF_SIZE 32768
> >> +
> > I think we should add a "/* seconds */"
> > so you don't have dig in the code
> > to see what interval is
> >> +#define MIN_UPCALL_TIMEOUT 5
> >> +#define DEF_UPCALL_TIMEOUT 30
> >> +#define MAX_UPCALL_TIMEOUT 600
> >> +
> >> /*
> >> * The gss mechanisms that we can handle
> >> */
> >> @@ -91,10 +96,20 @@ struct clnt_upcall_info {
> >> char *service;
> >> };
> >>
> >> +struct upcall_thread_info {
> >> + TAILQ_ENTRY(upcall_thread_info) list;
> >> + pthread_t tid;
> >> + struct timespec timeout;
> >> + uid_t uid;
> >> + int fd;
> >> + bool cancelled;
> >> +};
> >> +
> >> void handle_krb5_upcall(struct clnt_info *clp);
> >> void handle_gssd_upcall(struct clnt_info *clp);
> >> void free_upcall_info(struct clnt_upcall_info *info);
> >> void gssd_free_client(struct clnt_info *clp);
> >> +int do_error_downcall(int k5_fd, uid_t uid, int err);
> >>
> >>
> >> #endif /* _RPC_GSSD_H_ */
> >> diff --git a/utils/gssd/gssd.man b/utils/gssd/gssd.man
> >> index 9ae6def9..20fea729 100644
> >> --- a/utils/gssd/gssd.man
> >> +++ b/utils/gssd/gssd.man
> >> @@ -8,7 +8,7 @@
> >> rpc.gssd \- RPCSEC_GSS daemon
> >> .SH SYNOPSIS
> >> .B rpc.gssd
> >> -.RB [ \-DfMnlvrH ]
> >> +.RB [ \-DfMnlvrHC ]
> >> .RB [ \-k
> >> .IR keytab ]
> >> .RB [ \-p
> >> @@ -17,6 +17,10 @@ rpc.gssd \- RPCSEC_GSS daemon
> >> .IR ccachedir ]
> >> .RB [ \-t
> >> .IR timeout ]
> >> +.RB [ \-T
> >> +.IR timeout ]
> >> +.RB [ \-U
> >> +.IR timeout ]
> >> .RB [ \-R
> >> .IR realm ]
> >> .SH INTRODUCTION
> >> @@ -275,7 +279,7 @@ seconds, which allows changing Kerberos tickets and identities frequently.
> >> The default is no explicit timeout, which means the kernel context will live
> >> the lifetime of the Kerberos service ticket used in its creation.
> >> .TP
> >> -.B -T timeout
> >> +.BI "-T " timeout
> >> Timeout, in seconds, to create an RPC connection with a server while
> >> establishing an authenticated gss context for a user.
> >> The default timeout is set to 5 seconds.
> >> @@ -283,6 +287,18 @@ If you get messages like "WARNING: can't create tcp rpc_clnt to server
> >> %servername% for user with uid %uid%: RPC: Remote system error -
> >> Connection timed out", you should consider an increase of this timeout.
> >> .TP
> >> +.BI "-U " timeout
> >> +Timeout, in seconds, for upcall threads. Threads executing longer than
> >> +.I timeout
> >> +seconds will be cancelled and an error of -ETIMEDOUT will be reported
> >> +to the kernel. The default
> >> +.I timeout
> >> +is 30 seconds. The minimum is 5 seconds. The maximum is 600 seconds.
> >> +.TP
> >> +.B -C
> >> +Instead of cancelling upcall threads that have timed out, cause an error
> >> +message to be logged to the syslog (no error will be reported to the kernel).
> >> +.TP
> >> .B -H
> >> Avoids setting $HOME to "/". This allows rpc.gssd to read per user k5identity
> >> files versus trying to read /.k5identity for each user.
> >> @@ -350,6 +366,17 @@ Equivalent to
> >> Equivalent to
> >> .BR -R .
> >> .TP
> >> +.B upcall-timeout
> >> +Equivalent to
> >> +.BR -U .
> >> +.TP
> >> +.B cancel-timed-out-upcalls
> >> +Setting to
> >> +.B false
> >> +is equivalent to providing the
> >> +.B -C
> >> +flag.
> >> +.TP
> >> .B set-home
> >> Setting to
> >> .B false
> >> diff --git a/utils/gssd/gssd_proc.c b/utils/gssd/gssd_proc.c
> >> index ba508b30..ac7b1d1c 100644
> >> --- a/utils/gssd/gssd_proc.c
> >> +++ b/utils/gssd/gssd_proc.c
> >> @@ -81,11 +81,23 @@
> >> #include "gss_names.h"
> >>
> >> extern pthread_mutex_t clp_lock;
> >> +extern pthread_mutex_t active_thread_list_lock;
> >> +extern int upcall_timeout;
> >> +extern TAILQ_HEAD(active_thread_list_head, upcall_thread_info) active_thread_list;
> >>
> >> /* Encryption types supported by the kernel rpcsec_gss code */
> >> int num_krb5_enctypes = 0;
> >> krb5_enctype *krb5_enctypes = NULL;
> >>
> >> +struct cleanup_args {
> >> + OM_uint32 *min_stat;
> >> + gss_buffer_t acceptor;
> >> + gss_buffer_t token;
> >> + struct authgss_private_data *pd;
> >> + AUTH **auth;
> >> + CLIENT **rpc_clnt;
> >> +};
> >> +
> >> /*
> >> * Parse the supported encryption type information
> >> */
> >> @@ -184,7 +196,7 @@ out_err:
> >> return;
> >> }
> >>
> >> -static int
> >> +int
> >> do_error_downcall(int k5_fd, uid_t uid, int err)
> >> {
> >> char buf[1024];
> >> @@ -607,14 +619,37 @@ out:
> >> return auth;
> >> }
> >>
> >> +static void
> >> +cleanup_handler(void *arg)
> >> +{
> >> + struct cleanup_args *args = (struct cleanup_args *)arg;
> >> +
> >> + gss_release_buffer(args->min_stat, args->acceptor);
> >> + if (args->token->value)
> >> + free(args->token->value);
> >> +#ifdef HAVE_AUTHGSS_FREE_PRIVATE_DATA
> >> + if (args->pd->pd_ctx_hndl.length != 0 || args->pd->pd_ctx != 0)
> >> + authgss_free_private_data(args->pd);
> >> +#endif
> >> + if (*args->auth)
> >> + AUTH_DESTROY(*args->auth);
> >> + if (*args->rpc_clnt)
> >> + clnt_destroy(*args->rpc_clnt);
> >> +}
> >> +
> >> /*
> >> * this code uses the userland rpcsec gss library to create a krb5
> >> * context on behalf of the kernel
> >> */
> >> static void
> >> -process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
> >> - char *tgtname, char *service)
> >> +process_krb5_upcall(struct clnt_upcall_info *info)
> >> {
> >> + struct clnt_info *clp = info->clp;
> >> + uid_t uid = info->uid;
> >> + int fd = info->fd;
> >> + char *srchost = info->srchost;
> >> + char *tgtname = info->target;
> >> + char *service = info->service;
> >> CLIENT *rpc_clnt = NULL;
> >> AUTH *auth = NULL;
> >> struct authgss_private_data pd;
> >> @@ -624,11 +659,13 @@ process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
> >> gss_name_t gacceptor = GSS_C_NO_NAME;
> >> gss_OID mech;
> >> gss_buffer_desc acceptor = {0};
> >> + struct cleanup_args cleanup_args = {&min_stat, &acceptor, &token, &pd, &auth, &rpc_clnt};
> >>
> >> token.length = 0;
> >> token.value = NULL;
> >> memset(&pd, 0, sizeof(struct authgss_private_data));
> >>
> >> + pthread_cleanup_push(cleanup_handler, &cleanup_args);
> >> /*
> >> * If "service" is specified, then the kernel is indicating that
> >> * we must use machine credentials for this request. (Regardless
> >> @@ -650,6 +687,7 @@ process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
> >> * used for this case is not important.
> >> *
> >> */
> >> + pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);
> >> if (uid != 0 || (uid == 0 && root_uses_machine_creds == 0 &&
> >> service == NULL)) {
> >>
> >> @@ -670,15 +708,21 @@ process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
> >> goto out_return_error;
> >> }
> >> }
> >> + pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
> >> + pthread_testcancel();
> >>
> >> + pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);
> >> if (!authgss_get_private_data(auth, &pd)) {
> >> printerr(1, "WARNING: Failed to obtain authentication "
> >> "data for user with uid %d for server %s\n",
> >> uid, clp->servername);
> >> goto out_return_error;
> >> }
> >> + pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
> >> + pthread_testcancel();
> >>
> >> /* Grab the context lifetime and acceptor name out of the ctx. */
> >> + pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);
> >> maj_stat = gss_inquire_context(&min_stat, pd.pd_ctx, NULL, &gacceptor,
> >> &lifetime_rec, &mech, NULL, NULL, NULL);
> >>
> >> @@ -690,37 +734,35 @@ process_krb5_upcall(struct clnt_info *clp, uid_t uid, int fd, char *srchost,
> >> get_hostbased_client_buffer(gacceptor, mech, &acceptor);
> >> gss_release_name(&min_stat, &gacceptor);
> >> }
> >> + pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
> >> + pthread_testcancel();
> >>
> >> /*
> >> * The serialization can mean turning pd.pd_ctx into a lucid context. If
> >> * that happens then the pd.pd_ctx will be unusable, so we must never
> >> * try to use it after this point.
> >> */
> >> + pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);
> >> if (serialize_context_for_kernel(&pd.pd_ctx, &token, &krb5oid, NULL)) {
> >> printerr(1, "WARNING: Failed to serialize krb5 context for "
> >> "user with uid %d for server %s\n",
> >> uid, clp->servername);
> >> goto out_return_error;
> >> }
> >> + pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
> >> + pthread_testcancel();
> >>
> >> do_downcall(fd, uid, &pd, &token, lifetime_rec, &acceptor);
> >>
> >> out:
> >> - gss_release_buffer(&min_stat, &acceptor);
> >> - if (token.value)
> >> - free(token.value);
> >> -#ifdef HAVE_AUTHGSS_FREE_PRIVATE_DATA
> >> - if (pd.pd_ctx_hndl.length != 0 || pd.pd_ctx != 0)
> >> - authgss_free_private_data(&pd);
> >> -#endif
> >> - if (auth)
> >> - AUTH_DESTROY(auth);
> >> - if (rpc_clnt)
> >> - clnt_destroy(rpc_clnt);
> >> + pthread_cleanup_pop(1);
> >>
> >> return;
> >>
> >> out_return_error:
> >> + pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
> >> + pthread_testcancel();
> >> +
> >> do_error_downcall(fd, uid, downcall_err);
> >> goto out;
> >> }
> >> @@ -786,38 +828,71 @@ void free_upcall_info(struct clnt_upcall_info *info)
> >> }
> >>
> >> static void
> >> -gssd_work_thread_fn(struct clnt_upcall_info *info)
> >> +cleanup_clnt_upcall_info(void *arg)
> >> {
> >> - process_krb5_upcall(info->clp, info->uid, info->fd, info->srchost, info->target, info->service);
> >> + struct clnt_upcall_info *info = (struct clnt_upcall_info *)arg;
> >> +
> >> free_upcall_info(info);
> >> }
> >>
> >> +static void
> >> +gssd_work_thread_fn(struct clnt_upcall_info *info)
> >> +{
> >> + pthread_cleanup_push(cleanup_clnt_upcall_info, info);
> >> + process_krb5_upcall(info);
> >> + pthread_cleanup_pop(1);
> >> +}
> >> +
> >> +static struct upcall_thread_info *
> >> +alloc_upcall_thread_info(void)
> >> +{
> >> + struct upcall_thread_info *info;
> >> +
> >> + info = malloc(sizeof(struct upcall_thread_info));
> >> + if (info == NULL)
> >> + return NULL;
> >> + memset(info, 0, sizeof(*info));
> >> + return info;
> >> +}
> >> +
> >> static int
> >> -start_upcall_thread(void (*func)(struct clnt_upcall_info *), void *info)
> >> +start_upcall_thread(void (*func)(struct clnt_upcall_info *), struct clnt_upcall_info *info)
> >> {
> >> pthread_attr_t attr;
> >> pthread_t th;
> >> + struct upcall_thread_info *tinfo;
> >> int ret;
> >>
> >> + tinfo = alloc_upcall_thread_info();
> >> + if (!tinfo)
> >> + return -ENOMEM;
> >> + tinfo->fd = info->fd;
> >> + tinfo->uid = info->uid;
> >> + tinfo->cancelled = false;
> >> +
> >> ret = pthread_attr_init(&attr);
> >> if (ret != 0) {
> >> printerr(0, "ERROR: failed to init pthread attr: ret %d: %s\n",
> >> ret, strerror(errno));
> >> - return ret;
> >> - }
> >> - ret = pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED);
> >> - if (ret != 0) {
> >> - printerr(0, "ERROR: failed to create pthread attr: ret %d: "
> >> - "%s\n", ret, strerror(errno));
> >> + free(tinfo);
> >> return ret;
> >> }
> >>
> >> ret = pthread_create(&th, &attr, (void *)func, (void *)info);
> >> - if (ret != 0)
> >> + if (ret != 0) {
> >> printerr(0, "ERROR: pthread_create failed: ret %d: %s\n",
> >> ret, strerror(errno));
> >> - else
> >> - printerr(0, "created thread id 0x%lx\n", th);
> >> + free(tinfo);
> >> + return ret;
> >> + }
> >> + printerr(1, "created thread id 0x%lx\n", th);
> > This will be removed...
> >> + tinfo->tid = th;
> >> + pthread_mutex_lock(&active_thread_list_lock);
> >> + clock_gettime(CLOCK_MONOTONIC, &tinfo->timeout);
> >> + tinfo->timeout.tv_sec += upcall_timeout;
> >> + TAILQ_INSERT_TAIL(&active_thread_list, tinfo, list);
> >> + pthread_mutex_unlock(&active_thread_list_lock);
> >> +
> >> return ret;
> >> }
> >>
> >>
> >
> > Overall I think the code is very well written with
> > one exception... The lack of comments. I think it
> > would be very useful to let the reader know what
> > you are doing and why.... But by no means is
> > that a show stopper. Nice work!
> >
> > I'm still doing more testing and nothing
> > is breaking... So it is looking pretty good!
> >
> > steved.
> >
>
> --
> Chuck Lever
>
>
>

2021-05-27 12:52:29

by Steve Dickson

[permalink] [raw]
Subject: Re: [nfs-utils RFC PATCH 2/2] gssd: add timeout for upcall threads



On 5/27/21 7:40 AM, Scott Mayhew wrote:
> On Wed, 26 May 2021, Steve Dickson wrote:
>> If people are going to used the -C flag they are saying they want
>> to ignore hung threads so I'm thinking with printerr(0) we would
>> be filling up their logs about messages they don't care about.
>> So I'm thinking we should change this to a printerr(1)
>
> Note that message could pop multiple times per thread even without the
> -C flag because cancellation isn't immediate (a thread needs to hit a
> cancellation point, which it won't actually do that until it comes back
> from wherever it's hanging). My thinking was leaving it with
> printerr(0) would make it blatantly obvious when something was wrong and
> needed to be investigated. I have no issue with changing it to
> printerr(1) though.
It would... but I've craft the debugging for a single -v
is errors only... Maybe I should mention that in the
man page... And looking at what you mention in the
man page for -C, it does say it will cause an error
to be logged... So I guess it makes sense to leave
it as is.

>
> Alternatively we could add another flag to struct upcall_thread_info to
> ensure that message only gets logged once per thread.
>
I think it is good as is...

>>
>> Overall I think the code is very well written with
>> one exception... The lack of comments. I think it
>> would be very useful to let the reader know what
>> you are doing and why.... But by no means is
>> that a show stopper. Nice work!
>
> I can go back and add some comments.
Well there aren't that many comments to
begin with.... So you are just following
the format... ;-)

Don't worry about it... How I will finish my testing
today... and do the commit with what we got..

Again... Nice work!!

steved.

2021-05-27 17:32:38

by Steve Dickson

[permalink] [raw]
Subject: Re: [nfs-utils RFC PATCH 2/2] gssd: add timeout for upcall threads

Hey!

Off-list...

On 5/26/21 1:08 PM, Steve Dickson wrote:
>> + free(tinfo);
>> + return ret;
>> + }
>> + printerr(1, "created thread id 0x%lx\n", th);
> This will be removed...
It turns out this tid is useful since the
tid is used in the do_downcall() db statement.

In general I've try to always used the function name
in the db statement so it is know where it is.
So maybe something like this:

pthread_t tid = pthread_self();

printerr(2, "start_upcall_thread(0x%lx): created thread id 0x%lx\n", tid, th);

steved.

P.S. After your final version, I'm going to follow up with a debug clean up
patch... So I can take care of it there... if you like.

2021-05-27 18:58:56

by Scott Mayhew

[permalink] [raw]
Subject: Re: [nfs-utils RFC PATCH 2/2] gssd: add timeout for upcall threads

On Thu, 27 May 2021, Steve Dickson wrote:

> Hey!
>
> Off-list...
>
> On 5/26/21 1:08 PM, Steve Dickson wrote:
> >> + free(tinfo);
> >> + return ret;
> >> + }
> >> + printerr(1, "created thread id 0x%lx\n", th);
> > This will be removed...
> It turns out this tid is useful since the
> tid is used in the do_downcall() db statement.

I already got rid of it!

>
> In general I've try to always used the function name
> in the db statement so it is know where it is.
> So maybe something like this:
>
> pthread_t tid = pthread_self();
>
> printerr(2, "start_upcall_thread(0x%lx): created thread id 0x%lx\n", tid, th);
>
> steved.
>
> P.S. After your final version, I'm going to follow up with a debug clean up
> patch... So I can take care of it there... if you like.

>

2021-05-27 19:00:11

by Olga Kornievskaia

[permalink] [raw]
Subject: Re: [nfs-utils RFC PATCH 2/2] gssd: add timeout for upcall threads

On Thu, May 27, 2021 at 8:52 AM Steve Dickson <[email protected]> wrote:
>
>
>
> On 5/27/21 7:40 AM, Scott Mayhew wrote:
> > On Wed, 26 May 2021, Steve Dickson wrote:
> >> If people are going to used the -C flag they are saying they want
> >> to ignore hung threads so I'm thinking with printerr(0) we would
> >> be filling up their logs about messages they don't care about.
> >> So I'm thinking we should change this to a printerr(1)
> >
> > Note that message could pop multiple times per thread even without the
> > -C flag because cancellation isn't immediate (a thread needs to hit a
> > cancellation point, which it won't actually do that until it comes back
> > from wherever it's hanging). My thinking was leaving it with
> > printerr(0) would make it blatantly obvious when something was wrong and
> > needed to be investigated. I have no issue with changing it to
> > printerr(1) though.
> It would... but I've craft the debugging for a single -v
> is errors only... Maybe I should mention that in the
> man page... And looking at what you mention in the
> man page for -C, it does say it will cause an error
> to be logged... So I guess it makes sense to leave
> it as is.
>
> >
> > Alternatively we could add another flag to struct upcall_thread_info to
> > ensure that message only gets logged once per thread.
> >
> I think it is good as is...
>
> >>
> >> Overall I think the code is very well written with
> >> one exception... The lack of comments. I think it
> >> would be very useful to let the reader know what
> >> you are doing and why.... But by no means is
> >> that a show stopper. Nice work!
> >
> > I can go back and add some comments.
> Well there aren't that many comments to
> begin with.... So you are just following
> the format... ;-)
>
> Don't worry about it... How I will finish my testing
> today... and do the commit with what we got..

Hi Steve,

Can you please provide a bit more time for review to happen?

> Again... Nice work!!

Yes, nice work. But, I object to the current code that sets canceling
threads as default. This way the code hides the problems that occur
instead of forcing people to fix them.


>
> steved.
>

2021-05-30 19:57:47

by Steve Dickson

[permalink] [raw]
Subject: Re: [nfs-utils RFC PATCH 2/2] gssd: add timeout for upcall threads

Hey!

Sorry for the delay... Red Hat just rejiggered my
entire email world... fun fun! ;-)

On 5/27/21 12:47 PM, Olga Kornievskaia wrote:
> On Thu, May 27, 2021 at 8:52 AM Steve Dickson <[email protected]> wrote:
>>
>>
>>
>> On 5/27/21 7:40 AM, Scott Mayhew wrote:
>>> On Wed, 26 May 2021, Steve Dickson wrote:
>>>> If people are going to used the -C flag they are saying they want
>>>> to ignore hung threads so I'm thinking with printerr(0) we would
>>>> be filling up their logs about messages they don't care about.
>>>> So I'm thinking we should change this to a printerr(1)
>>>
>>> Note that message could pop multiple times per thread even without the
>>> -C flag because cancellation isn't immediate (a thread needs to hit a
>>> cancellation point, which it won't actually do that until it comes back
>>> from wherever it's hanging). My thinking was leaving it with
>>> printerr(0) would make it blatantly obvious when something was wrong and
>>> needed to be investigated. I have no issue with changing it to
>>> printerr(1) though.
>> It would... but I've craft the debugging for a single -v
>> is errors only... Maybe I should mention that in the
>> man page... And looking at what you mention in the
>> man page for -C, it does say it will cause an error
>> to be logged... So I guess it makes sense to leave
>> it as is.
>>
>>>
>>> Alternatively we could add another flag to struct upcall_thread_info to
>>> ensure that message only gets logged once per thread.
>>>
>> I think it is good as is...
>>
>>>>
>>>> Overall I think the code is very well written with
>>>> one exception... The lack of comments. I think it
>>>> would be very useful to let the reader know what
>>>> you are doing and why.... But by no means is
>>>> that a show stopper. Nice work!
>>>
>>> I can go back and add some comments.
>> Well there aren't that many comments to
>> begin with.... So you are just following
>> the format... ;-)
>>
>> Don't worry about it... How I will finish my testing
>> today... and do the commit with what we got..
>
> Hi Steve,
>
> Can you please provide a bit more time for review to happen?
Fair enough... Scott a V3 version on last Thur.

>
>> Again... Nice work!!
>
> Yes, nice work. But, I object to the current code that sets canceling
> threads as default. This way the code hides the problems that occur
> instead of forcing people to fix them.
Scott correct me if I'm wrong...

If the upcall is canceled (which is the default) the
upcall is failed causing the mount to fail and
a message is logged.

If the upcall is not canceled (using the -C flag)
the upcall continues to hang, but only on message
is logged about the hang... and the mount will
continue to hang.

See 'scan_active_thread_list()' the 'case EBUSY:' case.

So in both cases a the problem will be logged.

steved.