From 002112e540aac881e80356ec8cd65c57b3b51f6d Mon Sep 17 00:00:00 2001
From: johann <johann>
Date: Mon, 8 Oct 2007 19:47:03 +0000
Subject: [PATCH] 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.
---
lnet/include/libcfs/libcfs.h | 7 +-
lnet/libcfs/debug.c | 88 +++++++++++++++++++++----
lnet/libcfs/linux/linux-proc.c | 113 +++++++++++++++++++++++++++++++++
lnet/libcfs/tracefile.c | 20 +++---
4 files changed, 203 insertions(+), 25 deletions(-)
diff --git a/lnet/include/libcfs/libcfs.h b/lnet/include/libcfs/libcfs.h
index b607c1aa96..82d293b6cd 100644
--- 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 a69d967e5f..baeaeac569 100644
--- 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 92cc8fe279..c317a5abf8 100644
--- 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 f40958f2f4..6d33b0db44 100644
--- 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 */
--
GitLab