Whamcloud - gitweb
LU-10401 procs: print new line based on distro
[fs/lustre-release.git] / libcfs / libcfs / debug.c
index d945a34..cd6cfdb 100644 (file)
@@ -23,7 +23,7 @@
  * Copyright (c) 2008, 2010, Oracle and/or its affiliates. All rights reserved.
  * Use is subject to license terms.
  *
- * Copyright (c) 2011, 2014, Intel Corporation.
+ * Copyright (c) 2011, 2017, Intel Corporation.
  */
 /*
  * This file is part of Lustre, http://www.lustre.org/
@@ -37,6 +37,7 @@
 
 # define DEBUG_SUBSYSTEM S_LNET
 
+#include <linux/ctype.h>
 #include <linux/kthread.h>
 #include <libcfs/libcfs.h>
 #include "tracefile.h"
@@ -48,14 +49,53 @@ module_param(libcfs_subsystem_debug, int, 0644);
 MODULE_PARM_DESC(libcfs_subsystem_debug, "Lustre kernel debug subsystem mask");
 EXPORT_SYMBOL(libcfs_subsystem_debug);
 
-unsigned int libcfs_debug = (D_CANTMASK |
-                            D_NETERROR | D_HA | D_CONFIG | D_IOCTL | D_LFSCK);
+unsigned int libcfs_debug = (D_CANTMASK | D_NETERROR | D_HA | D_CONFIG |
+                            D_IOCTL | D_LFSCK | D_TTY);
 module_param(libcfs_debug, int, 0644);
 MODULE_PARM_DESC(libcfs_debug, "Lustre kernel debug mask");
 EXPORT_SYMBOL(libcfs_debug);
 
+static int libcfs_param_debug_mb_set(const char *val,
+                                    cfs_kernel_param_arg_t *kp)
+{
+       int rc;
+       unsigned int num;
+
+       rc = kstrtouint(val, 0, &num);
+       if (rc < 0)
+               return rc;
+
+       num = cfs_trace_set_debug_mb(num);
+
+       *((unsigned int *)kp->arg) = num;
+       num = cfs_trace_get_debug_mb();
+       if (num)
+               /* This value is more precise */
+               *((unsigned int *)kp->arg) = num;
+
+       return 0;
+}
+
+/*
+ * While debug_mb setting look like unsigned int, in fact
+ * it needs quite a bunch of extra processing, so we define special
+ * debug_mb parameter type with corresponding methods to handle this case
+ */
+static struct kernel_param_ops param_ops_debug_mb = {
+       .set = libcfs_param_debug_mb_set,
+       .get = param_get_uint,
+};
+
+#define param_check_debug_mb(name, p) \
+               __param_check(name, p, unsigned int)
+
 static unsigned int libcfs_debug_mb;
-module_param(libcfs_debug_mb, uint, 0644);
+#ifdef HAVE_KERNEL_PARAM_OPS
+module_param(libcfs_debug_mb, debug_mb, 0644);
+#else
+module_param_call(libcfs_debug_mb, libcfs_param_debug_mb_set, param_get_uint,
+                 &param_ops_debug_mb, 0644);
+#endif
 MODULE_PARM_DESC(libcfs_debug_mb, "Total debug buffer size.");
 
 unsigned int libcfs_printk = D_CANTMASK;
@@ -66,16 +106,125 @@ unsigned int libcfs_console_ratelimit = 1;
 module_param(libcfs_console_ratelimit, uint, 0644);
 MODULE_PARM_DESC(libcfs_console_ratelimit, "Lustre kernel debug console ratelimit (0 to disable)");
 
+static int param_set_delay_minmax(const char *val,
+                                 cfs_kernel_param_arg_t *kp,
+                                 long min, long max)
+{
+       long d;
+       int sec;
+       int rc;
+
+       rc = kstrtoint(val, 0, &sec);
+       if (rc)
+               return -EINVAL;
+
+       /* The sysfs setting is in centiseconds */
+       d = cfs_time_seconds(sec) / 100;
+       if (d < min || d > max)
+               return -EINVAL;
+
+       *((unsigned int *)kp->arg) = d;
+
+       return 0;
+}
+
+static int param_get_delay(char *buffer, cfs_kernel_param_arg_t *kp)
+{
+       unsigned int d = *(unsigned int *)kp->arg;
+
+       param_get_byte(buffer, kp);
+       return sprintf(buffer, "%lu%c", jiffies_to_msecs(d * 10) / MSEC_PER_SEC,
+                      strnchr(buffer, PAGE_SIZE, '\n') ? '\n' : '\0');
+}
+
 unsigned int libcfs_console_max_delay;
-module_param(libcfs_console_max_delay, uint, 0644);
+unsigned int libcfs_console_min_delay;
+
+static int param_set_console_max_delay(const char *val,
+                                      cfs_kernel_param_arg_t *kp)
+{
+       return param_set_delay_minmax(val, kp,
+                                     libcfs_console_min_delay, INT_MAX);
+}
+
+static struct kernel_param_ops param_ops_console_max_delay = {
+       .set = param_set_console_max_delay,
+       .get = param_get_delay,
+};
+
+#define param_check_console_max_delay(name, p) \
+               __param_check(name, p, unsigned int)
+
+#ifdef HAVE_KERNEL_PARAM_OPS
+module_param(libcfs_console_max_delay, console_max_delay, 0644);
+#else
+module_param_call(libcfs_console_max_delay, param_set_console_max_delay,
+                 param_get_delay, &param_ops_console_max_delay, 0644);
+#endif
 MODULE_PARM_DESC(libcfs_console_max_delay, "Lustre kernel debug console max delay (jiffies)");
 
-unsigned int libcfs_console_min_delay;
-module_param(libcfs_console_min_delay, uint, 0644);
+static int param_set_console_min_delay(const char *val,
+                                      cfs_kernel_param_arg_t *kp)
+{
+       return param_set_delay_minmax(val, kp,
+                                     1, libcfs_console_max_delay);
+}
+
+static struct kernel_param_ops param_ops_console_min_delay = {
+       .set = param_set_console_min_delay,
+       .get = param_get_delay,
+};
+
+#define param_check_console_min_delay(name, p) \
+               __param_check(name, p, unsigned int)
+
+#ifdef HAVE_KERNEL_PARAM_OPS
+module_param(libcfs_console_min_delay, console_min_delay, 0644);
+#else
+module_param_call(libcfs_console_min_delay, param_set_console_min_delay,
+                 param_get_delay, &param_ops_console_min_delay, 0644);
+#endif
 MODULE_PARM_DESC(libcfs_console_min_delay, "Lustre kernel debug console min delay (jiffies)");
 
+static int param_set_uint_minmax(const char *val,
+                                cfs_kernel_param_arg_t *kp,
+                                unsigned int min, unsigned int max)
+{
+       unsigned int num;
+       int ret;
+
+       if (!val)
+               return -EINVAL;
+
+       ret = kstrtouint(val, 0, &num);
+       if (ret < 0 || num < min || num > max)
+               return -EINVAL;
+
+       *((unsigned int *)kp->arg) = num;
+       return 0;
+}
+
+static int param_set_uintpos(const char *val,
+                            cfs_kernel_param_arg_t *kp)
+{
+       return param_set_uint_minmax(val, kp, 1, -1);
+}
+
+static struct kernel_param_ops param_ops_uintpos = {
+       .set = param_set_uintpos,
+       .get = param_get_uint,
+};
+
+#define param_check_uintpos(name, p) \
+               __param_check(name, p, unsigned int)
+
 unsigned int libcfs_console_backoff = CDEBUG_DEFAULT_BACKOFF;
-module_param(libcfs_console_backoff, uint, 0644);
+#ifdef HAVE_KERNEL_PARAM_OPS
+module_param(libcfs_console_backoff, uintpos, 0644);
+#else
+module_param_call(libcfs_console_backoff, param_set_uintpos, param_get_uint,
+                 &param_ops_uintpos, 0644);
+#endif
 MODULE_PARM_DESC(libcfs_console_backoff, "Lustre kernel debug console backoff factor");
 
 unsigned int libcfs_debug_binary = 1;
@@ -87,6 +236,7 @@ unsigned int libcfs_catastrophe;
 EXPORT_SYMBOL(libcfs_catastrophe);
 
 unsigned int libcfs_watchdog_ratelimit = 300;
+EXPORT_SYMBOL(libcfs_watchdog_ratelimit);
 
 unsigned int libcfs_panic_on_lbug = 1;
 module_param(libcfs_panic_on_lbug, uint, 0644);
@@ -95,20 +245,23 @@ MODULE_PARM_DESC(libcfs_panic_on_lbug, "Lustre kernel panic on LBUG");
 atomic_t libcfs_kmemory = ATOMIC_INIT(0);
 EXPORT_SYMBOL(libcfs_kmemory);
 
-static wait_queue_head_t debug_ctlwq;
+static DECLARE_COMPLETION(debug_complete);
 
 char libcfs_debug_file_path_arr[PATH_MAX] = LIBCFS_DEBUG_FILE_PATH_DEFAULT;
+EXPORT_SYMBOL(libcfs_debug_file_path_arr);
 
 /* We need to pass a pointer here, but elsewhere this must be a const */
-static char *libcfs_debug_file_path;
+static char *libcfs_debug_file_path = LIBCFS_DEBUG_FILE_PATH_DEFAULT;
 module_param(libcfs_debug_file_path, charp, 0644);
 MODULE_PARM_DESC(libcfs_debug_file_path,
                 "Path for dumping debug logs, set 'NONE' to prevent log dumping");
 
 int libcfs_panic_in_progress;
 
-/* libcfs_debug_token2mask() expects the returned
- * string in lower-case */
+/*
+ * libcfs_debug_token2mask() expects the returned
+ * string in lower-case
+ */
 static const char *libcfs_debug_subsys2str(int subsys)
 {
        static const char *libcfs_debug_subsystems[] = LIBCFS_DEBUG_SUBSYS_NAMES;
@@ -119,8 +272,10 @@ static const char *libcfs_debug_subsys2str(int subsys)
        return libcfs_debug_subsystems[subsys];
 }
 
-/* libcfs_debug_token2mask() expects the returned
- * string in lower-case */
+/*
+ * libcfs_debug_token2mask() expects the returned
+ * string in lower-case
+ */
 static const char *libcfs_debug_dbg2str(int debug)
 {
        static const char *libcfs_debug_masks[] = LIBCFS_DEBUG_MASKS_NAMES;
@@ -134,79 +289,78 @@ static const char *libcfs_debug_dbg2str(int debug)
 int
 libcfs_debug_mask2str(char *str, int size, int mask, int is_subsys)
 {
-        const char *(*fn)(int bit) = is_subsys ? libcfs_debug_subsys2str :
-                                                 libcfs_debug_dbg2str;
-        int           len = 0;
-        const char   *token;
-        int           i;
-
-        if (mask == 0) {                        /* "0" */
-                if (size > 0)
-                        str[0] = '0';
-                len = 1;
-        } else {                                /* space-separated tokens */
-                for (i = 0; i < 32; i++) {
-                        if ((mask & (1 << i)) == 0)
-                                continue;
-
-                        token = fn(i);
-                        if (token == NULL)              /* unused bit */
-                                continue;
-
-                        if (len > 0) {                  /* separator? */
-                                if (len < size)
-                                        str[len] = ' ';
-                                len++;
-                        }
-
-                        while (*token != 0) {
-                                if (len < size)
-                                        str[len] = *token;
-                                token++;
-                                len++;
-                        }
-                }
-        }
-
-        /* terminate 'str' */
-        if (len < size)
-                str[len] = 0;
-        else
-                str[size - 1] = 0;
-
-        return len;
+       const char *(*fn)(int bit) = is_subsys ? libcfs_debug_subsys2str :
+                                                libcfs_debug_dbg2str;
+       int len = 0;
+       const char *token;
+       int i;
+
+       if (mask == 0) {                        /* "0" */
+               if (size > 0)
+                       str[0] = '0';
+               len = 1;
+       } else {                                /* space-separated tokens */
+               for (i = 0; i < 32; i++) {
+                       if ((mask & BIT(i)) == 0)
+                               continue;
+
+                       token = fn(i);
+                       if (token == NULL)      /* unused bit */
+                               continue;
+
+                       if (len > 0) {          /* separator? */
+                               if (len < size)
+                                       str[len] = ' ';
+                               len++;
+                       }
+
+                       while (*token != 0) {
+                               if (len < size)
+                                       str[len] = *token;
+                               token++;
+                               len++;
+                       }
+               }
+       }
+
+       /* terminate 'str' */
+       if (len < size)
+               str[len] = 0;
+       else
+               str[size - 1] = 0;
+
+       return len;
 }
 
 int
 libcfs_debug_str2mask(int *mask, const char *str, int is_subsys)
 {
-        const char *(*fn)(int bit) = is_subsys ? libcfs_debug_subsys2str :
-                                                 libcfs_debug_dbg2str;
-        int         m = 0;
-        int         matched;
-        int         n;
-        int         t;
-
-        /* Allow a number for backwards compatibility */
-
-        for (n = strlen(str); n > 0; n--)
-                if (!isspace(str[n-1]))
-                        break;
-        matched = n;
-
-        if ((t = sscanf(str, "%i%n", &m, &matched)) >= 1 &&
-            matched == n) {
-                /* don't print warning for lctl set_param debug=0 or -1 */
-                if (m != 0 && m != -1)
-                        CWARN("You are trying to use a numerical value for the "
-                              "mask - this will be deprecated in a future "
-                              "release.\n");
-                *mask = m;
-                return 0;
-        }
-
-        return cfs_str2mask(str, fn, mask, is_subsys ? 0 : D_CANTMASK,
-                            0xffffffff);
+       const char *(*fn)(int bit) = is_subsys ? libcfs_debug_subsys2str :
+                                                libcfs_debug_dbg2str;
+       int m = 0;
+       int matched;
+       int n;
+       int t;
+
+       /* Allow a number for backwards compatibility */
+       for (n = strlen(str); n > 0; n--)
+               if (!isspace(str[n-1]))
+                       break;
+       matched = n;
+
+       t = sscanf(str, "%i%n", &m, &matched);
+       if (t >= 1 && matched == n) {
+               /* don't print warning for lctl set_param debug=0 or -1 */
+               if (m != 0 && m != -1)
+                       CWARN("You are trying to use a numerical value for the "
+                             "mask - this will be deprecated in a future "
+                             "release.\n");
+               *mask = m;
+               return 0;
+       }
+
+       return cfs_str2mask(str, fn, mask, is_subsys ? 0 : D_CANTMASK,
+                           0xffffffff);
 }
 
 /**
@@ -214,23 +368,21 @@ libcfs_debug_str2mask(int *mask, const char *str, int is_subsys)
  */
 void libcfs_debug_dumplog_internal(void *arg)
 {
-       static time_t last_dump_time;
-       time_t current_time;
+       static time64_t last_dump_time;
+       time64_t current_time;
        void *journal_info;
 
        journal_info = current->journal_info;
        current->journal_info = NULL;
-
-       current_time = cfs_time_current_sec();
+       current_time = ktime_get_real_seconds();
 
        if (strncmp(libcfs_debug_file_path_arr, "NONE", 4) != 0 &&
            current_time > last_dump_time) {
                last_dump_time = current_time;
                snprintf(debug_file_name, sizeof(debug_file_name) - 1,
-                        "%s.%ld.%ld", libcfs_debug_file_path_arr,
-                        current_time, (uintptr_t)arg);
-               printk(KERN_ALERT "LustreError: dumping log to %s\n",
-                      debug_file_name);
+                        "%s.%lld.%ld", libcfs_debug_file_path_arr,
+                        (s64)current_time, (uintptr_t)arg);
+               pr_alert("LustreError: dumping log to %s\n", debug_file_name);
                cfs_tracefile_dump_all_pages(debug_file_name);
                libcfs_run_debug_log_upcall(debug_file_name);
        }
@@ -240,45 +392,46 @@ void libcfs_debug_dumplog_internal(void *arg)
 static int libcfs_debug_dumplog_thread(void *arg)
 {
        libcfs_debug_dumplog_internal(arg);
-       wake_up(&debug_ctlwq);
+       complete(&debug_complete);
        return 0;
 }
 
+static DEFINE_MUTEX(libcfs_debug_dumplog_lock);
+
 void libcfs_debug_dumplog(void)
 {
-       wait_queue_t wait;
-       struct task_struct    *dumper;
+       struct task_struct *dumper;
+
        ENTRY;
 
-       /* we're being careful to ensure that the kernel thread is
-        * able to set our state to running as it exits before we
-        * get to schedule() */
-       init_waitqueue_entry(&wait, current);
-       set_current_state(TASK_INTERRUPTIBLE);
-       add_wait_queue(&debug_ctlwq, &wait);
+       if (mutex_trylock(&libcfs_debug_dumplog_lock) == 0)
+               return;
 
+       /* If a previous call was interrupted, debug_complete->done
+        * might be elevated, and so we won't actually wait here.
+        * So we reinit the completion to ensure we wait for
+        * one thread to complete, though it might not be the one
+        * we start if there are overlaping thread.
+        */
+       reinit_completion(&debug_complete);
        dumper = kthread_run(libcfs_debug_dumplog_thread,
-                            (void *)(long)current_pid(),
+                            (void *)(long)current->pid,
                             "libcfs_debug_dumper");
        if (IS_ERR(dumper))
-               printk(KERN_ERR "LustreError: cannot start log dump thread:"
-                      " %ld\n", PTR_ERR(dumper));
+               pr_err("LustreError: cannot start log dump thread: rc = %ld\n",
+                      PTR_ERR(dumper));
        else
-               schedule();
+               wait_for_completion_interruptible(&debug_complete);
 
-       /* be sure to teardown if cfs_create_thread() failed */
-       remove_wait_queue(&debug_ctlwq, &wait);
-       set_current_state(TASK_RUNNING);
+       mutex_unlock(&libcfs_debug_dumplog_lock);
 }
 EXPORT_SYMBOL(libcfs_debug_dumplog);
 
 int libcfs_debug_init(unsigned long bufsize)
 {
-       int    rc = 0;
+       int rc = 0;
        unsigned int max = libcfs_debug_mb;
 
-       init_waitqueue_head(&debug_ctlwq);
-
        if (libcfs_console_max_delay <= 0 || /* not set by user or */
            libcfs_console_min_delay <= 0 || /* set to invalid values */
            libcfs_console_min_delay >= libcfs_console_max_delay) {
@@ -292,55 +445,65 @@ int libcfs_debug_init(unsigned long bufsize)
                        sizeof(libcfs_debug_file_path_arr));
        }
 
-       /* If libcfs_debug_mb is set to an invalid value or uninitialized
-        * then just make the total buffers smp_num_cpus * TCD_MAX_PAGES */
-       if (max > cfs_trace_max_debug_mb() || max < num_possible_cpus()) {
+       /* If libcfs_debug_mb is uninitialized then just make the
+        * total buffers smp_num_cpus * TCD_MAX_PAGES
+        */
+       if (max < num_possible_cpus()) {
                max = TCD_MAX_PAGES;
        } else {
                max = (max / num_possible_cpus());
                max = (max << (20 - PAGE_SHIFT));
        }
-       rc = cfs_tracefile_init(max);
-
-        if (rc == 0)
-                libcfs_register_panic_notifier();
 
-        return rc;
+       rc = cfs_tracefile_init(max);
+       if (rc)
+               return rc;
+
+       libcfs_register_panic_notifier();
+       kernel_param_lock(THIS_MODULE);
+       if (libcfs_debug_mb == 0)
+               libcfs_debug_mb = cfs_trace_get_debug_mb();
+       kernel_param_unlock(THIS_MODULE);
+       return rc;
 }
 
 int libcfs_debug_cleanup(void)
 {
-        libcfs_unregister_panic_notifier();
-        cfs_tracefile_exit();
-        return 0;
+       libcfs_unregister_panic_notifier();
+       kernel_param_lock(THIS_MODULE);
+       cfs_tracefile_exit();
+       kernel_param_unlock(THIS_MODULE);
+       return 0;
 }
 
 int libcfs_debug_clear_buffer(void)
 {
-        cfs_trace_flush_pages();
-        return 0;
+       cfs_trace_flush_pages();
+       return 0;
 }
 
-/* Debug markers, although printed by S_LNET
- * should not be be marked as such. */
+/*
+ * Debug markers, although printed by S_LNET
+ * should not be be marked as such.
+ */
 #undef DEBUG_SUBSYSTEM
 #define DEBUG_SUBSYSTEM S_UNDEFINED
 int libcfs_debug_mark_buffer(const char *text)
 {
-        CDEBUG(D_TRACE,"***************************************************\n");
-        LCONSOLE(D_WARNING, "DEBUG MARKER: %s\n", text);
-        CDEBUG(D_TRACE,"***************************************************\n");
+       CDEBUG(D_TRACE, "**************************************************\n");
+       LCONSOLE(D_WARNING, "DEBUG MARKER: %s\n", text);
+       CDEBUG(D_TRACE, "**************************************************\n");
 
-        return 0;
+       return 0;
 }
 #undef DEBUG_SUBSYSTEM
 #define DEBUG_SUBSYSTEM S_LNET
 
 long libcfs_log_return(struct libcfs_debug_msg_data *msgdata, long rc)
 {
-        libcfs_debug_msg(msgdata, "Process leaving (rc=%lu : %ld : %lx)\n",
-                         rc, rc, rc);
-        return rc;
+       libcfs_debug_msg(msgdata, "Process leaving (rc=%lu : %ld : %lx)\n",
+                        rc, rc, rc);
+       return rc;
 }
 EXPORT_SYMBOL(libcfs_log_return);