LU-14518 libcfs: print CFS_FAIL_CHECK() location

Print the file/function/line where cfs_fail_loc is hit.
This allows better debugging of issues with this code.

This adds the CDEBUG_LIMIT_LOC() macro to allow printing
the location passed to the caller instead of the function,
file, and line number where the macro is located.

Signed-off-by: Andreas Dilger <adilger@whamcloud.com>
Change-Id: Ieadace61b014d3576c0535f181256c728c7ec6f8
Reviewed-on: https://review.whamcloud.com/c/fs/lustre-release/+/53451
Reviewed-by: Arshad Hussain <arshad.hussain@aeoncomputing.com>
Reviewed-by: Timothy Day <timday@amazon.com>
Reviewed-by: Oleg Drokin <green@whamcloud.com>
Tested-by: jenkins <devops@whamcloud.com>
Tested-by: Maloo <maloo@whamcloud.com>

diff --git a/libcfs/include/libcfs/libcfs_debug.h b/libcfs/include/libcfs/libcfs_debug.h
index 12a61e6..4995273 100644 (file)
--- a/libcfs/include/libcfs/libcfs_debug.h
+++ b/libcfs/include/libcfs/libcfs_debug.h
@@ -150,6 +150,14 @@ do {                                                                       \
                          mask, &cdls, format, ## __VA_ARGS__);         \
 } while (0)
 
+#  define CDEBUG_LIMIT_LOC(file, func, line, mask, format, ...)                \
+do {                                                                   \
+       static struct cfs_debug_limit_state cdls;                       \
+                                                                       \
+       __CDEBUG_WITH_LOC(file, func, line,                             \
+                         mask, &cdls, format, ## __VA_ARGS__);         \
+} while (0)
+
 # else /* !CDEBUG_ENABLED */
 static inline int cfs_cdebug_show(unsigned int mask, unsigned int subsystem)
 {
@@ -157,6 +165,7 @@ static inline int cfs_cdebug_show(unsigned int mask, unsigned int subsystem)
 }
 #  define CDEBUG(mask, format, ...) (void)(0)
 #  define CDEBUG_LIMIT(mask, format, ...) (void)(0)
+#  define CDEBUG_LIMIT_LOC(file, func, line, mask, format, ...) (void)(0)
 #  warning "CDEBUG IS DISABLED. THIS SHOULD NEVER BE DONE FOR PRODUCTION!"
 # endif /* CDEBUG_ENABLED */
 

diff --git a/libcfs/include/libcfs/libcfs_fail.h b/libcfs/include/libcfs/libcfs_fail.h
index 472a7fb..994a853 100644 (file)
--- a/libcfs/include/libcfs/libcfs_fail.h
+++ b/libcfs/include/libcfs/libcfs_fail.h
@@ -40,7 +40,8 @@ extern wait_queue_head_t cfs_race_waitq;
 extern int cfs_race_state;
 
 int __cfs_fail_check_set(__u32 id, __u32 value, int set);
-int __cfs_fail_timeout_set(__u32 id, __u32 value, int ms, int set);
+int __cfs_fail_timeout_set(const char *file, const char *func, int line,
+                          __u32 id, __u32 value, int ms, int set);
 
 enum {
        CFS_FAIL_LOC_NOSET = 0,
@@ -84,23 +85,27 @@ static inline bool CFS_FAIL_PRECHECK(__u32 id)
               (cfs_fail_loc & id & CFS_FAULT)));
 }
 
-#define UNLIKELY_CHECK_SET(id, value, set, quiet) \
-       (unlikely(cfs_fail_check_set(id, value, set, quiet)))
+#define UNLIKELY_CHECK_SET(id, value, set, quiet)                      \
+       (unlikely(cfs_fail_check_set_loc(__FILE__, __func__, __LINE__,  \
+                                        id, value, set, quiet)))
 
-static inline int cfs_fail_check_set(__u32 id, __u32 value, int set, int quiet)
+static inline int cfs_fail_check_set_loc(const char *file, const char *func,
+                                        int line, __u32 id, __u32 value,
+                                        int set, int quiet)
 {
-       unsigned long failed_once = cfs_fail_loc & CFS_FAILED; /* ok if racy */
        int ret = 0;
 
-       if (CFS_FAIL_PRECHECK(id) &&
-           (ret = __cfs_fail_check_set(id, value, set))) {
-               if (quiet && failed_once) {
-                       CDEBUG(D_INFO, "*** cfs_fail_loc=%x, val=%u***\n",
-                              id, value);
-               } else {
-                       LCONSOLE_INFO("*** cfs_fail_loc=%x, val=%u***\n",
-                                     id, value);
-               }
+       if (CFS_FAIL_PRECHECK(id)) {
+               /* set failed_once before the CFS_FAILED flag is set below */
+               unsigned long failed_once = cfs_fail_loc & CFS_FAILED;
+
+               ret = __cfs_fail_check_set(id, value, set);
+               if (ret)
+                       CDEBUG_LIMIT_LOC(file, func, line,
+                                        (quiet && failed_once) ?
+                                               D_INFO : D_CONSOLE,
+                                        "*** cfs_fail_loc=%x, val=%u***\n",
+                                        id, value);
        }
 
        return ret;
@@ -142,14 +147,17 @@ static inline int cfs_fail_check_set(__u32 id, __u32 value, int set, int quiet)
        UNLIKELY_CHECK_SET(id, value, CFS_FAIL_LOC_RESET, 1)
 
 #define UNLIKELY_TIMEOUT_SET(id, value, ms, set) \
-       (unlikely(cfs_fail_timeout_set(id, value, ms, set)))
+       (unlikely(cfs_fail_timeout_set_loc(__FILE__, __func__, __LINE__, \
+                                          id, value, ms, set)))
 
-static inline int cfs_fail_timeout_set(__u32 id, __u32 value, int ms, int set)
+static inline int cfs_fail_timeout_set_loc(const char *file, const char *func,
+                                          int line, __u32 id, __u32 value,
+                                          int ms, int set)
 {
        if (CFS_FAIL_PRECHECK(id))
-               return __cfs_fail_timeout_set(id, value, ms, set);
-       else
-               return 0;
+               return __cfs_fail_timeout_set(file, func, line, id, value, ms,
+                                             set);
+       return 0;
 }
 
 /* If id hit cfs_fail_loc, sleep for seconds or milliseconds */
@@ -179,13 +187,15 @@ static inline int cfs_fail_timeout_set(__u32 id, __u32 value, int ms, int set)
  * sleep. The next thread that calls with the same fail_loc wakes up
  * the first and continues.
  */
-static inline void cfs_race(__u32 id)
+static inline void cfs_race_loc(const char *file, const char *func, int line,
+                               __u32 id)
 {
        if (CFS_FAIL_PRECHECK(id)) {
                if (unlikely(__cfs_fail_check_set(id, 0, CFS_FAIL_LOC_NOSET))) {
                        int rc;
                        cfs_race_state = 0;
-                       CERROR("cfs_race id %x sleeping\n", id);
+                       CDEBUG_LIMIT_LOC(file, func, line, D_ERROR,
+                                        "cfs_race id %x sleeping\n", id);
                        /*
                         * XXX: don't wait forever as there is no guarantee
                         * that this branch is executed first. for testing
@@ -194,15 +204,18 @@ static inline void cfs_race(__u32 id)
                        rc = wait_event_interruptible_timeout(cfs_race_waitq,
                                                      cfs_race_state != 0,
                                                      cfs_time_seconds(5));
-                       CERROR("cfs_fail_race id %x awake: rc=%d\n", id, rc);
+                       CDEBUG_LIMIT_LOC(file, func, line, D_ERROR,
+                                        "cfs_fail_race id %x awake: rc=%d\n",
+                                        id, rc);
                } else {
-                       CERROR("cfs_fail_race id %x waking\n", id);
+                       CDEBUG_LIMIT_LOC(file, func, line, D_ERROR,
+                                        "cfs_fail_race id %x waking\n", id);
                        cfs_race_state = 1;
                        wake_up(&cfs_race_waitq);
                }
        }
 }
-#define CFS_RACE(id) cfs_race(id)
+#define CFS_RACE(id) cfs_race_loc(__FILE__, __func__, __LINE__, id)
 
 /**
  * Wait on race.
@@ -211,35 +224,41 @@ static inline void cfs_race(__u32 id)
  * but subseqent callers of this won't sleep. Until another thread that calls
  * cfs_race_wakeup(), the first thread will be woken up and continue.
  */
-static inline void cfs_race_wait(__u32 id)
+static inline void cfs_race_wait_loc(const char *file, const char *func,
+                                    int line, __u32 id)
 {
        if (CFS_FAIL_PRECHECK(id)) {
                if (unlikely(__cfs_fail_check_set(id, 0, CFS_FAIL_LOC_NOSET))) {
                        int rc;
 
                        cfs_race_state = 0;
-                       CERROR("cfs_race id %x sleeping\n", id);
+                       CDEBUG_LIMIT_LOC(file, func, line, D_ERROR,
+                                        "cfs_race id %x sleeping\n", id);
                        rc = wait_event_interruptible(cfs_race_waitq,
                                                      cfs_race_state != 0);
-                       CERROR("cfs_fail_race id %x awake: rc=%d\n", id, rc);
+                       CDEBUG_LIMIT_LOC(file, func, line, D_ERROR,
+                                        "cfs_fail_race id %x awake: rc=%d\n",
+                                        id, rc);
                }
        }
 }
-#define CFS_RACE_WAIT(id) cfs_race_wait(id)
+#define CFS_RACE_WAIT(id) cfs_race_wait_loc(__FILE__, __func__, __LINE__, id)
 
 /**
  * Wake up the thread that is waiting on the matching fail_loc.
  */
-static inline void cfs_race_wakeup(__u32 id)
+static inline void cfs_race_wakeup_loc(const char *file, const char *func,
+                                      int line, __u32 id)
 {
        if (CFS_FAIL_PRECHECK(id)) {
                if (likely(!__cfs_fail_check_set(id, 0, CFS_FAIL_LOC_NOSET))) {
-                       CERROR("cfs_fail_race id %x waking\n", id);
+                       CDEBUG_LIMIT_LOC(file, func, line, D_ERROR,
+                                        "cfs_fail_race id %x waking\n", id);
                        cfs_race_state = 1;
                        wake_up(&cfs_race_waitq);
                }
        }
 }
-#define CFS_RACE_WAKEUP(id) cfs_race_wakeup(id)
+#define CFS_RACE_WAKEUP(id) cfs_race_wakeup_loc(__FILE__, __func__, __LINE__,id)
 
 #endif /* _LIBCFS_FAIL_H */

diff --git a/libcfs/libcfs/fail.c b/libcfs/libcfs/fail.c
index 5623e3f..f7365f9 100644 (file)
--- a/libcfs/libcfs/fail.c
+++ b/libcfs/libcfs/fail.c
@@ -128,25 +128,30 @@ int __cfs_fail_check_set(u32 id, u32 value, int set)
 }
 EXPORT_SYMBOL(__cfs_fail_check_set);
 
-int __cfs_fail_timeout_set(u32 id, u32 value, int ms, int set)
+int __cfs_fail_timeout_set(const char *file, const char *func, const int line,
+                          u32 id, u32 value, int ms, int set)
 {
        ktime_t till = ktime_add_ms(ktime_get(), ms);
        int ret;
 
        ret = __cfs_fail_check_set(id, value, set);
        if (ret && likely(ms > 0)) {
-               CERROR("cfs_fail_timeout id %x sleeping for %dms\n", id, ms);
+               CDEBUG_LIMIT_LOC(file, func, line, D_ERROR,
+                                "cfs_fail_timeout id %x sleeping for %dms\n",
+                                id, ms);
                while (ktime_before(ktime_get(), till)) {
                        schedule_timeout_uninterruptible(cfs_time_seconds(1)
                                                         / 10);
                        set_current_state(TASK_RUNNING);
                        if (!cfs_fail_loc) {
-                               CERROR("cfs_fail_timeout interrupted\n");
+                               CDEBUG_LIMIT_LOC(file, func, line, D_ERROR,
+                                             "cfs_fail_timeout interrupted\n");
                                break;
                        }
                }
                if (cfs_fail_loc)
-                       CERROR("cfs_fail_timeout id %x awake\n", id);
+                       CDEBUG_LIMIT_LOC(file, func, line, D_ERROR,
+                                       "cfs_fail_timeout id %x awake\n", id);
        }
        return ret;
 }