1df6c8
From e2af9793014ad67859aa73088765a52307cbe466 Mon Sep 17 00:00:00 2001
1df6c8
From: Csaba Henk <csaba@redhat.com>
1df6c8
Date: Tue, 7 Jan 2020 19:43:05 +0100
1df6c8
Subject: [PATCH 346/346] fuse: degrade logging of write failure to fuse device
1df6c8
1df6c8
Problem:
1df6c8
1df6c8
FUSE uses failures of communicating with /dev/fuse with various
1df6c8
errnos to indicate in-kernel conditions to userspace. Some of these
1df6c8
shouldn't be handled as an application error. Also the standard
1df6c8
POSIX errno description should not be shown as they are misleading
1df6c8
in this context.
1df6c8
1df6c8
Solution:
1df6c8
1df6c8
When writing to the fuse device, the caller of the respective
1df6c8
convenience routine can mask those errnos which don't qualify to
1df6c8
be an error for the application in that context, so then those
1df6c8
shall be reported at DEBUG level.
1df6c8
1df6c8
The possible non-standard errnos are reported with their
1df6c8
POSIX name instead of their description to avoid confusion.
1df6c8
(Eg. for ENOENT we don't log "no such file or directory",
1df6c8
we log indeed literal "ENOENT".)
1df6c8
1df6c8
Upstream on https://review.gluster.org/23974
1df6c8
> Change-Id: I510158843e4b1d482bdc496c2e97b1860dc1ba93
1df6c8
> updates: bz#1193929
1df6c8
> Signed-off-by: Csaba Henk <csaba@redhat.com>
1df6c8
1df6c8
BUG: 1763208
1df6c8
Change-Id: Ib1676bb334ed153ce74ae1c0413fc0e58fb388c7
1df6c8
Signed-off-by: Csaba Henk <csaba@redhat.com>
1df6c8
Reviewed-on: https://code.engineering.redhat.com/gerrit/189056
1df6c8
Tested-by: RHGS Build Bot <nigelb@redhat.com>
1df6c8
Reviewed-by: Sunil Kumar Heggodu Gopala Acharya <sheggodu@redhat.com>
1df6c8
---
1df6c8
 xlators/mount/fuse/src/fuse-bridge.c | 78 +++++++++++++++++++++++++++++++++---
1df6c8
 xlators/mount/fuse/src/fuse-bridge.h |  9 ++++-
1df6c8
 2 files changed, 80 insertions(+), 7 deletions(-)
1df6c8
1df6c8
diff --git a/xlators/mount/fuse/src/fuse-bridge.c b/xlators/mount/fuse/src/fuse-bridge.c
1df6c8
index ebe5c28..6e99053 100644
1df6c8
--- a/xlators/mount/fuse/src/fuse-bridge.c
1df6c8
+++ b/xlators/mount/fuse/src/fuse-bridge.c
1df6c8
@@ -198,7 +198,7 @@ fusedump_setup_meta(struct iovec *iovs, char *dir,
1df6c8
 
1df6c8
 static int
1df6c8
 check_and_dump_fuse_W(fuse_private_t *priv, struct iovec *iov_out, int count,
1df6c8
-                      ssize_t res)
1df6c8
+                      ssize_t res, errnomask_t errnomask)
1df6c8
 {
1df6c8
     char w = 'W';
1df6c8
     struct iovec diov[4] = {
1df6c8
@@ -216,8 +216,59 @@ check_and_dump_fuse_W(fuse_private_t *priv, struct iovec *iov_out, int count,
1df6c8
     struct fuse_out_header *fouh = NULL;
1df6c8
 
1df6c8
     if (res == -1) {
1df6c8
-        gf_log_callingfn("glusterfs-fuse", GF_LOG_ERROR,
1df6c8
-                         "writing to fuse device failed: %s", strerror(errno));
1df6c8
+        const char *errdesc = NULL;
1df6c8
+        gf_loglevel_t loglevel = GF_LOG_ERROR;
1df6c8
+
1df6c8
+        /* If caller masked the errno, then it
1df6c8
+         * does not indicate an error at the application
1df6c8
+         * level, so we degrade the log severity to DEBUG.
1df6c8
+         */
1df6c8
+        if (errnomask && errno < ERRNOMASK_MAX &&
1df6c8
+            GET_ERRNO_MASK(errnomask, errno))
1df6c8
+            loglevel = GF_LOG_DEBUG;
1df6c8
+
1df6c8
+        switch (errno) {
1df6c8
+            /* The listed errnos are FUSE status indicators,
1df6c8
+             * not legit values according to POSIX (see write(3p)),
1df6c8
+             * so resolving them according to the standard
1df6c8
+             * POSIX interpretation would be misleading.
1df6c8
+             */
1df6c8
+            case ENOENT:
1df6c8
+                errdesc = "ENOENT";
1df6c8
+                break;
1df6c8
+            case ENOTDIR:
1df6c8
+                errdesc = "ENOTDIR";
1df6c8
+                break;
1df6c8
+            case ENODEV:
1df6c8
+                errdesc = "ENODEV";
1df6c8
+                break;
1df6c8
+            case EPERM:
1df6c8
+                errdesc = "EPERM";
1df6c8
+                break;
1df6c8
+            case ENOMEM:
1df6c8
+                errdesc = "ENOMEM";
1df6c8
+                break;
1df6c8
+            case ENOTCONN:
1df6c8
+                errdesc = "ENOTCONN";
1df6c8
+                break;
1df6c8
+            case ECONNREFUSED:
1df6c8
+                errdesc = "ECONNREFUSED";
1df6c8
+                break;
1df6c8
+            case EOVERFLOW:
1df6c8
+                errdesc = "EOVERFLOW";
1df6c8
+                break;
1df6c8
+            case EBUSY:
1df6c8
+                errdesc = "EBUSY";
1df6c8
+                break;
1df6c8
+            case ENOTEMPTY:
1df6c8
+                errdesc = "ENOTEMPTY";
1df6c8
+                break;
1df6c8
+            default:
1df6c8
+                errdesc = strerror(errno);
1df6c8
+        }
1df6c8
+
1df6c8
+        gf_log_callingfn("glusterfs-fuse", loglevel,
1df6c8
+                         "writing to fuse device failed: %s", errdesc);
1df6c8
         return errno;
1df6c8
     }
1df6c8
 
1df6c8
@@ -282,7 +333,7 @@ send_fuse_iov(xlator_t *this, fuse_in_header_t *finh, struct iovec *iov_out,
1df6c8
     gf_log("glusterfs-fuse", GF_LOG_TRACE, "writev() result %d/%d %s", res,
1df6c8
            fouh->len, res == -1 ? strerror(errno) : "");
1df6c8
 
1df6c8
-    return check_and_dump_fuse_W(priv, iov_out, count, res);
1df6c8
+    return check_and_dump_fuse_W(priv, iov_out, count, res, NULL);
1df6c8
 }
1df6c8
 
1df6c8
 static int
1df6c8
@@ -353,6 +404,15 @@ fuse_invalidate_entry(xlator_t *this, uint64_t fuse_ino)
1df6c8
         fouh->unique = 0;
1df6c8
         fouh->error = FUSE_NOTIFY_INVAL_ENTRY;
1df6c8
 
1df6c8
+        if (ENOENT < ERRNOMASK_MAX)
1df6c8
+            MASK_ERRNO(node->errnomask, ENOENT);
1df6c8
+        if (ENOTDIR < ERRNOMASK_MAX)
1df6c8
+            MASK_ERRNO(node->errnomask, ENOTDIR);
1df6c8
+        if (EBUSY < ERRNOMASK_MAX)
1df6c8
+            MASK_ERRNO(node->errnomask, EBUSY);
1df6c8
+        if (ENOTEMPTY < ERRNOMASK_MAX)
1df6c8
+            MASK_ERRNO(node->errnomask, ENOTEMPTY);
1df6c8
+
1df6c8
         if (dentry->name) {
1df6c8
             nlen = strlen(dentry->name);
1df6c8
             fouh->len = sizeof(*fouh) + sizeof(*fnieo) + nlen + 1;
1df6c8
@@ -437,6 +497,9 @@ fuse_invalidate_inode(xlator_t *this, uint64_t fuse_ino)
1df6c8
     fniio->off = 0;
1df6c8
     fniio->len = -1;
1df6c8
 
1df6c8
+    if (ENOENT < ERRNOMASK_MAX)
1df6c8
+        MASK_ERRNO(node->errnomask, ENOENT);
1df6c8
+
1df6c8
     fuse_log_eh(this, "Invalidated inode %" PRIu64 " (gfid: %s)", fuse_ino,
1df6c8
                 uuid_utoa(inode->gfid));
1df6c8
     gf_log("glusterfs-fuse", GF_LOG_TRACE,
1df6c8
@@ -482,6 +545,7 @@ fuse_timed_message_new(void)
1df6c8
     /* should be NULL if not set */
1df6c8
     dmsg->fuse_message_body = NULL;
1df6c8
     INIT_LIST_HEAD(&dmsg->next);
1df6c8
+    memset(dmsg->errnomask, 0, sizeof(dmsg->errnomask));
1df6c8
 
1df6c8
     return dmsg;
1df6c8
 }
1df6c8
@@ -680,6 +744,8 @@ fuse_interrupt(xlator_t *this, fuse_in_header_t *finh, void *msg,
1df6c8
         dmsg->fuse_out_header.unique = finh->unique;
1df6c8
         dmsg->fuse_out_header.len = sizeof(dmsg->fuse_out_header);
1df6c8
         dmsg->fuse_out_header.error = -EAGAIN;
1df6c8
+        if (ENOENT < ERRNOMASK_MAX)
1df6c8
+            MASK_ERRNO(dmsg->errnomask, ENOENT);
1df6c8
         timespec_now(&dmsg->scheduled_ts);
1df6c8
         timespec_adjust_delta(&dmsg->scheduled_ts,
1df6c8
                               (struct timespec){0, 10000000});
1df6c8
@@ -4848,7 +4914,7 @@ notify_kernel_loop(void *data)
1df6c8
         iov_out.iov_base = node->inval_buf;
1df6c8
         iov_out.iov_len = len;
1df6c8
         rv = sys_writev(priv->fd, &iov_out, 1);
1df6c8
-        check_and_dump_fuse_W(priv, &iov_out, 1, rv);
1df6c8
+        check_and_dump_fuse_W(priv, &iov_out, 1, rv, node->errnomask);
1df6c8
 
1df6c8
         GF_FREE(node);
1df6c8
 
1df6c8
@@ -4940,7 +5006,7 @@ timed_response_loop(void *data)
1df6c8
         iovs[1] = (struct iovec){dmsg->fuse_message_body,
1df6c8
                                  len - sizeof(struct fuse_out_header)};
1df6c8
         rv = sys_writev(priv->fd, iovs, 2);
1df6c8
-        check_and_dump_fuse_W(priv, iovs, 2, rv);
1df6c8
+        check_and_dump_fuse_W(priv, iovs, 2, rv, dmsg->errnomask);
1df6c8
 
1df6c8
         fuse_timed_message_free(dmsg);
1df6c8
 
1df6c8
diff --git a/xlators/mount/fuse/src/fuse-bridge.h b/xlators/mount/fuse/src/fuse-bridge.h
1df6c8
index cf4479c..d2d462c 100644
1df6c8
--- a/xlators/mount/fuse/src/fuse-bridge.h
1df6c8
+++ b/xlators/mount/fuse/src/fuse-bridge.h
1df6c8
@@ -195,14 +195,20 @@ struct fuse_private {
1df6c8
 };
1df6c8
 typedef struct fuse_private fuse_private_t;
1df6c8
 
1df6c8
+typedef uint64_t errnomask_t[2];
1df6c8
+#define MASK_ERRNO(mask, n) ((mask)[(n) >> 6] |= ((uint64_t)1 << ((n)&63)))
1df6c8
+#define GET_ERRNO_MASK(mask, n) ((mask)[(n) >> 6] & ((uint64_t)1 << ((n)&63)))
1df6c8
+#define ERRNOMASK_MAX (64 * (sizeof(errnomask_t) / sizeof(uint64_t)))
1df6c8
+
1df6c8
 #define INVAL_BUF_SIZE                                                         \
1df6c8
     (sizeof(struct fuse_out_header) +                                          \
1df6c8
      max(sizeof(struct fuse_notify_inval_inode_out),                           \
1df6c8
          sizeof(struct fuse_notify_inval_entry_out) + NAME_MAX + 1))
1df6c8
 
1df6c8
 struct fuse_invalidate_node {
1df6c8
-    char inval_buf[INVAL_BUF_SIZE];
1df6c8
+    errnomask_t errnomask;
1df6c8
     struct list_head next;
1df6c8
+    char inval_buf[INVAL_BUF_SIZE];
1df6c8
 };
1df6c8
 typedef struct fuse_invalidate_node fuse_invalidate_node_t;
1df6c8
 
1df6c8
@@ -210,6 +216,7 @@ struct fuse_timed_message {
1df6c8
     struct fuse_out_header fuse_out_header;
1df6c8
     void *fuse_message_body;
1df6c8
     struct timespec scheduled_ts;
1df6c8
+    errnomask_t errnomask;
1df6c8
     struct list_head next;
1df6c8
 };
1df6c8
 typedef struct fuse_timed_message fuse_timed_message_t;
1df6c8
-- 
1df6c8
1.8.3.1
1df6c8