Branch b1_6

b=11686
i=adilger
i=green

Severity   : enhancement
Bugzilla   : 11686
Description: Console message flood
Details    : Make cdls ratelimiting more tunable by adding several tunable in
	     procfs /proc/sys/lnet/console_{min,max}_delay_centisecs and
	     /proc/sys/lnet/console_backoff.

diff --git a/lnet/include/libcfs/libcfs.h b/lnet/include/libcfs/libcfs.h
index b607c1a..82d293b 100644 (file)
--- a/lnet/include/libcfs/libcfs.h
+++ b/lnet/include/libcfs/libcfs.h
@@ -74,6 +74,9 @@ extern unsigned int libcfs_stack;
 extern unsigned int libcfs_debug;
 extern unsigned int libcfs_printk;
 extern unsigned int libcfs_console_ratelimit;
+extern cfs_duration_t libcfs_console_max_delay;
+extern cfs_duration_t libcfs_console_min_delay;
+extern unsigned int libcfs_console_backoff;
 extern unsigned int libcfs_debug_binary;
 extern char debug_file_path[1024];
 
@@ -164,7 +167,9 @@ extern unsigned int libcfs_panic_on_lbug;
 # define DEBUG_SUBSYSTEM S_UNDEFINED
 #endif
 
-#define CDEBUG_MAX_LIMIT 600
+#define CDEBUG_DEFAULT_MAX_DELAY (cfs_time_seconds(600))         /* jiffies */
+#define CDEBUG_DEFAULT_MIN_DELAY ((cfs_time_seconds(1) + 1) / 2) /* jiffies */
+#define CDEBUG_DEFAULT_BACKOFF   2
 typedef struct {
         cfs_time_t      cdls_next;
         int             cdls_count;

diff --git a/lnet/libcfs/debug.c b/lnet/libcfs/debug.c
index a69d967..baeaeac 100644 (file)
--- a/lnet/libcfs/debug.c
+++ b/lnet/libcfs/debug.c
@@ -47,6 +47,15 @@ EXPORT_SYMBOL(libcfs_printk);
 unsigned int libcfs_console_ratelimit = 1;
 EXPORT_SYMBOL(libcfs_console_ratelimit);
 
+cfs_duration_t libcfs_console_max_delay;
+EXPORT_SYMBOL(libcfs_console_max_delay);
+
+cfs_duration_t libcfs_console_min_delay;
+EXPORT_SYMBOL(libcfs_console_min_delay);
+
+unsigned int libcfs_console_backoff = CDEBUG_DEFAULT_BACKOFF;
+EXPORT_SYMBOL(libcfs_console_backoff);
+
 unsigned int libcfs_debug_binary = 1;
 EXPORT_SYMBOL(libcfs_debug_binary);
 
@@ -420,6 +429,8 @@ int libcfs_debug_init(unsigned long bufsize)
         int    rc;
 
         cfs_waitq_init(&debug_ctlwq);
+        libcfs_console_max_delay = CDEBUG_DEFAULT_MAX_DELAY;
+        libcfs_console_min_delay = CDEBUG_DEFAULT_MIN_DELAY;
         rc = tracefile_init();
 
         if (rc == 0)
@@ -479,6 +490,9 @@ static char source_nid[16];
 /* 0 indicates no messages to console, 1 is errors, > 1 is all debug messages */
 static int toconsole = 1;
 unsigned int libcfs_console_ratelimit = 1;
+cfs_duration_t libcfs_console_max_delay;
+cfs_duration_t libcfs_console_min_delay;
+unsigned int libcfs_console_backoff = CDEBUG_DEFAULT_BACKOFF;
 #else /* !HAVE_CATAMOUNT_DATA_H */
 #ifdef HAVE_NETDB_H
 #include <sys/utsname.h>
@@ -520,6 +534,12 @@ int libcfs_debug_init(unsigned long bufsize)
 #ifdef HAVE_CATAMOUNT_DATA_H
         char *debug_console = NULL;
         char *debug_ratelimit = NULL;
+        char *debug_max_delay = NULL;
+        char *debug_min_delay = NULL;
+        char *debug_backoff = NULL;
+
+        libcfs_console_max_delay = CDEBUG_DEFAULT_MAX_DELAY;
+        libcfs_console_min_delay = CDEBUG_DEFAULT_MIN_DELAY;
 
         snprintf(source_nid, sizeof(source_nid) - 1, "%u", _my_pnid);
         source_pid = _my_pid;
@@ -532,7 +552,47 @@ int libcfs_debug_init(unsigned long bufsize)
         debug_ratelimit = getenv("LIBLUSTRE_DEBUG_CONSOLE_RATELIMIT");
         if (debug_ratelimit != NULL) {
                 libcfs_console_ratelimit = strtoul(debug_ratelimit, NULL, 0);
-                CDEBUG(D_INFO, "set liblustre console ratelimit to %u\n", libcfs_console_ratelimit);
+                CDEBUG(D_INFO, "set liblustre console ratelimit to %u\n",
+                                libcfs_console_ratelimit);
+        }
+        debug_max_delay = getenv("LIBLUSTRE_DEBUG_CONSOLE_MAX_DELAY");
+        if (debug_max_delay != NULL)
+                libcfs_console_max_delay =
+                            cfs_time_seconds(strtoul(debug_max_delay, NULL, 0));
+        debug_min_delay = getenv("LIBLUSTRE_DEBUG_CONSOLE_MIN_DELAY");
+        if (debug_min_delay != NULL)
+                libcfs_console_min_delay =
+                            cfs_time_seconds(strtoul(debug_min_delay, NULL, 0));
+        if (debug_min_delay || debug_max_delay) {
+                if (!libcfs_console_max_delay || !libcfs_console_min_delay ||
+                    libcfs_console_max_delay < libcfs_console_min_delay) {
+                        libcfs_console_max_delay = CDEBUG_DEFAULT_MAX_DELAY;
+                        libcfs_console_min_delay = CDEBUG_DEFAULT_MIN_DELAY;
+                        CDEBUG(D_INFO, "LIBLUSTRE_DEBUG_CONSOLE_MAX_DELAY "
+                                       "should be greater than "
+                                       "LIBLUSTRE_DEBUG_CONSOLE_MIN_DELAY "
+                                       "and both parameters should be non-null"
+                                       ": restore default values\n");
+                } else {
+                        CDEBUG(D_INFO, "set liblustre console max delay to %lus"
+                                       " and min delay to %lus\n",
+                               (cfs_duration_t)
+                                     cfs_duration_sec(libcfs_console_max_delay),
+                               (cfs_duration_t)
+                                    cfs_duration_sec(libcfs_console_min_delay));
+                }
+        }
+        debug_backoff = getenv("LIBLUSTRE_DEBUG_CONSOLE_BACKOFF");
+        if (debug_backoff != NULL) {
+                libcfs_console_backoff = strtoul(debug_backoff, NULL, 0);
+                if (libcfs_console_backoff <= 0) {
+                        libcfs_console_backoff = CDEBUG_DEFAULT_BACKOFF;
+                        CDEBUG(D_INFO, "LIBLUSTRE_DEBUG_CONSOLE_BACKOFF <= 0: "
+                                       "restore default value\n");
+                } else {
+                        CDEBUG(D_INFO, "set liblustre console backoff to %u\n",
+                               libcfs_console_backoff);
+                }
         }
 #else
         struct utsname myname;
@@ -670,10 +730,6 @@ libcfs_debug_vmsg2(cfs_debug_limit_state_t *cdls,
         if (console) {
                 /* check rate limit for console */
                 if (cdls != NULL) {
-                        cfs_time_t t = cdls->cdls_next +
-                                       cfs_time_seconds(CDEBUG_MAX_LIMIT + 10);
-                        cfs_duration_t  dmax = cfs_time_seconds(CDEBUG_MAX_LIMIT);
-
                         if (libcfs_console_ratelimit &&
                                 cdls->cdls_next != 0 &&     /* not first time ever */
                                 !cfs_time_after(cfs_time_current(), cdls->cdls_next)) {
@@ -683,16 +739,22 @@ libcfs_debug_vmsg2(cfs_debug_limit_state_t *cdls,
                                 goto out_file;
                         }
 
-                        if (cfs_time_after(cfs_time_current(), t)) {
+                        if (cfs_time_after(cfs_time_current(), cdls->cdls_next +
+                                           libcfs_console_max_delay +
+                                           cfs_time_seconds(10))) {
                                 /* last timeout was a long time ago */
-                                cdls->cdls_delay /= 8;
+                                cdls->cdls_delay /= libcfs_console_backoff * 4;
                         } else {
-                                cdls->cdls_delay *= 2;
-
-                                if (cdls->cdls_delay < CFS_TICK)
-                                        cdls->cdls_delay = CFS_TICK;
-                                else if (cdls->cdls_delay > dmax)
-                                        cdls->cdls_delay = dmax;
+                                cdls->cdls_delay *= libcfs_console_backoff;
+
+                                if (cdls->cdls_delay <
+                                                libcfs_console_min_delay)
+                                        cdls->cdls_delay =
+                                                libcfs_console_min_delay;
+                                else if (cdls->cdls_delay >
+                                                libcfs_console_max_delay)
+                                        cdls->cdls_delay =
+                                                libcfs_console_max_delay;
                         }
 
                         /* ensure cdls_next is never zero after it's been seen */

diff --git a/lnet/libcfs/linux/linux-proc.c b/lnet/libcfs/linux/linux-proc.c
index 92cc8fe..c317a5a 100644 (file)
--- a/lnet/libcfs/linux/linux-proc.c
+++ b/lnet/libcfs/linux/linux-proc.c
@@ -68,6 +68,9 @@ enum {
         PSDEV_SUBSYSTEM_DEBUG,    /* control debugging */
         PSDEV_PRINTK,             /* force all messages to console */
         PSDEV_CONSOLE_RATELIMIT,  /* ratelimit console messages */
+        PSDEV_CONSOLE_MAX_DELAY_CS, /* maximum delay over which we skip messages */
+        PSDEV_CONSOLE_MIN_DELAY_CS, /* initial delay over which we skip messages */
+        PSDEV_CONSOLE_BACKOFF,    /* delay increase factor */
         PSDEV_DEBUG_PATH,         /* crashdump log location */
         PSDEV_DEBUG_DUMP_PATH,    /* crashdump tracelog location */
         PSDEV_LNET_UPCALL,        /* User mode upcall script  */
@@ -195,6 +198,95 @@ static int __proc_debug_mb(void *data, int write,
 
 DECLARE_PROC_HANDLER(proc_debug_mb)
 
+int LL_PROC_PROTO(proc_console_max_delay_cs)
+{
+        int rc, max_delay_cs;
+        cfs_sysctl_table_t dummy = *table;
+        cfs_duration_t d;
+
+        dummy.data = &max_delay_cs;
+        dummy.proc_handler = &proc_dointvec;
+
+        if (!write) { /* read */
+                max_delay_cs = cfs_duration_sec(libcfs_console_max_delay * 100);
+                rc = ll_proc_dointvec(&dummy, write, filp, buffer, lenp, ppos);
+                return rc;
+        }
+
+        /* write */
+        max_delay_cs = 0;
+        rc = ll_proc_dointvec(&dummy, write, filp, buffer, lenp, ppos);
+        if (rc < 0)
+                return rc;
+        if (max_delay_cs <= 0)
+                return -EINVAL;
+
+        d = cfs_time_seconds(max_delay_cs) / 100;
+        if (d == 0 || d < libcfs_console_min_delay)
+                return -EINVAL;
+        libcfs_console_max_delay = d;
+
+        return rc;
+}
+
+int LL_PROC_PROTO(proc_console_min_delay_cs)
+{
+        int rc, min_delay_cs;
+        cfs_sysctl_table_t dummy = *table;
+        cfs_duration_t d;
+
+        dummy.data = &min_delay_cs;
+        dummy.proc_handler = &proc_dointvec;
+
+        if (!write) { /* read */
+                min_delay_cs = cfs_duration_sec(libcfs_console_min_delay * 100);
+                rc = ll_proc_dointvec(&dummy, write, filp, buffer, lenp, ppos);
+                return rc;
+        }
+
+        /* write */
+        min_delay_cs = 0;
+        rc = ll_proc_dointvec(&dummy, write, filp, buffer, lenp, ppos);
+        if (rc < 0)
+                return rc;
+        if (min_delay_cs <= 0)
+                return -EINVAL;
+
+        d = cfs_time_seconds(min_delay_cs) / 100;
+        if (d == 0 || d > libcfs_console_max_delay)
+                return -EINVAL;
+        libcfs_console_min_delay = d;
+
+        return rc;
+}
+
+int LL_PROC_PROTO(proc_console_backoff)
+{
+        int rc, backoff;
+        cfs_sysctl_table_t dummy = *table;
+
+        dummy.data = &backoff;
+        dummy.proc_handler = &proc_dointvec;
+
+        if (!write) { /* read */
+                backoff= libcfs_console_backoff;
+                rc = ll_proc_dointvec(&dummy, write, filp, buffer, lenp, ppos);
+                return rc;
+        }
+
+        /* write */
+        backoff = 0;
+        rc = ll_proc_dointvec(&dummy, write, filp, buffer, lenp, ppos);
+        if (rc < 0)
+                return rc;
+        if (backoff <= 0)
+                return -EINVAL;
+
+        libcfs_console_backoff = backoff;
+
+        return rc;
+}
+
 static cfs_sysctl_table_t lnet_table[] = {
         /*
          * NB No .strategy entries have been provided since sysctl(8) prefers
@@ -232,6 +324,27 @@ static cfs_sysctl_table_t lnet_table[] = {
                 .mode     = 0644,
                 .proc_handler = &proc_dointvec
         },
+        {
+                .ctl_name = PSDEV_CONSOLE_MAX_DELAY_CS,
+                .procname = "console_max_delay_centisecs",
+                .maxlen   = sizeof(int),
+                .mode     = 0644,
+                .proc_handler = &proc_console_max_delay_cs
+        },
+        {
+                .ctl_name = PSDEV_CONSOLE_MIN_DELAY_CS,
+                .procname = "console_min_delay_centisecs",
+                .maxlen   = sizeof(int),
+                .mode     = 0644,
+                .proc_handler = &proc_console_min_delay_cs
+        },
+        {
+                .ctl_name = PSDEV_CONSOLE_BACKOFF,
+                .procname = "console_backoff",
+                .maxlen   = sizeof(int),
+                .mode     = 0644,
+                .proc_handler = &proc_console_backoff
+        },
 
         {
                 .ctl_name = PSDEV_DEBUG_PATH,

diff --git a/lnet/libcfs/tracefile.c b/lnet/libcfs/tracefile.c
index f40958f..6d33b0d 100644 (file)
--- a/lnet/libcfs/tracefile.c
+++ b/lnet/libcfs/tracefile.c
@@ -350,10 +350,6 @@ console:
         }
 
         if (cdls != NULL) {
-                cfs_time_t      t = cdls->cdls_next +
-                                    cfs_time_seconds(CDEBUG_MAX_LIMIT + 10);
-                cfs_duration_t  dmax = cfs_time_seconds(CDEBUG_MAX_LIMIT);
-
                 if (libcfs_console_ratelimit &&
                     cdls->cdls_next != 0 &&     /* not first time ever */
                     !cfs_time_after(cfs_time_current(), cdls->cdls_next)) {
@@ -364,16 +360,18 @@ console:
                         return 1;
                 }
 
-                if (cfs_time_after(cfs_time_current(), t)) {
+                if (cfs_time_after(cfs_time_current(), cdls->cdls_next +
+                                                       libcfs_console_max_delay
+                                                       + cfs_time_seconds(10))) {
                         /* last timeout was a long time ago */
-                        cdls->cdls_delay /= 8;
+                        cdls->cdls_delay /= libcfs_console_backoff * 4;
                 } else {
-                        cdls->cdls_delay *= 2;
+                        cdls->cdls_delay *= libcfs_console_backoff;
 
-                        if (cdls->cdls_delay < CFS_TICK)
-                                cdls->cdls_delay = CFS_TICK;
-                        else if (cdls->cdls_delay > dmax)
-                                cdls->cdls_delay = dmax;
+                        if (cdls->cdls_delay < libcfs_console_min_delay)
+                                cdls->cdls_delay = libcfs_console_min_delay;
+                        else if (cdls->cdls_delay > libcfs_console_max_delay)
+                                cdls->cdls_delay = libcfs_console_max_delay;
                 }
 
                 /* ensure cdls_next is never zero after it's been seen */