2008-02-19 21:31:11

by Hawkes Steve-FSH016

[permalink] [raw]
Subject: printk_ratelimit and net_ratelimit conflict and tunable behavior

The printk_ratelimit() and net_ratelimit() functions are coupled and
interfere with each other. Each has their own tunable parameters to
control their respective rate limiting feature, but they share common
state variables, causing the rate limiting to behave in an unexpected
fashion when the tunables for each are set to different values.

Also, changes to rate limiting tunable parameters do not always take
effect
properly since state is not recomputed when changes occur. For example,
if
the ratelimit_burst tunable value is increased while rate limiting
is occurring, the change doesn't take full effect until at least enough
time between messages occurs so that the toks value reaches
ratelimit_burst * ratelimit_jiffies. This can result in messages being
suppressed when they should be allowed.

The patch below for the 2.6.24 kernel eliminates the above issues.
Please
consider this or a suitable alternative for inclusion in future kernel
releases.

Please copy me at steve dot hawkes at motorola dot com in follow-up
postings,
if you'd be so kind (spammers excluded).

Thank you,
Steve Hawkes

----

diff -Naup OLD/include/linux/kernel.h NEW/include/linux/kernel.h
--- OLD/include/linux/kernel.h 2008-02-19 10:02:07.461496000 -0600
+++ NEW/include/linux/kernel.h 2008-02-19 10:45:32.858306000 -0600
@@ -196,8 +196,20 @@ static inline int log_buf_copy(char *des

unsigned long int_sqrt(unsigned long);

+struct printk_ratelimit_state
+{
+ unsigned long toks;
+ unsigned long last_jiffies;
+ int missed;
+ int limit_jiffies;
+ int limit_burst;
+ char const *facility;
+};
+
+extern int __printk_ratelimit(int ratelimit_jiffies,
+ int ratelimit_burst,
+ struct printk_ratelimit_state *state);
extern int printk_ratelimit(void);
-extern int __printk_ratelimit(int ratelimit_jiffies, int
ratelimit_burst);
extern bool printk_timed_ratelimit(unsigned long *caller_jiffies,
unsigned int interval_msec);

diff -Naup OLD/net/core/utils.c NEW/net/core/utils.c
--- OLD/net/core/utils.c 2008-02-19 10:01:26.442370000 -0600
+++ NEW/net/core/utils.c 2008-02-19 10:46:45.026731000 -0600
@@ -41,7 +41,18 @@ EXPORT_SYMBOL(net_msg_warn);
*/
int net_ratelimit(void)
{
- return __printk_ratelimit(net_msg_cost, net_msg_burst);
+ static struct printk_ratelimit_state limit_state = {
+ .toks = 10 * 5 * HZ,
+ .last_jiffies = 0,
+ .missed = 0,
+ .limit_jiffies = 5 * HZ,
+ .limit_burst = 10,
+ .facility = "net"
+ };
+
+ return __printk_ratelimit(net_msg_cost,
+ net_msg_burst,
+ &limit_state);
}
EXPORT_SYMBOL(net_ratelimit);

diff -Naup OLD/kernel/printk.c NEW/kernel/print.c
--- OLD/kernel/printk.c 2008-02-19 10:00:47.359068000 -0600
+++ NEW/kernel/printk.c 2008-02-19 10:46:30.748743000 -0600
@@ -1236,37 +1236,47 @@ void tty_write_message(struct tty_struct
}

/*
- * printk rate limiting, lifted from the networking subsystem.
+ * printk rate limiting.
*
- * This enforces a rate limit: not more than one kernel message
- * every printk_ratelimit_jiffies to make a denial-of-service
- * attack impossible.
+ * This enforces a rate limit to mitigate denial-of-service attacks:
+ * not more than ratelimit_burst messages every ratelimit_jiffies.
*/
-int __printk_ratelimit(int ratelimit_jiffies, int ratelimit_burst)
+int __printk_ratelimit(int ratelimit_jiffies,
+ int ratelimit_burst,
+ struct printk_ratelimit_state *state)
{
static DEFINE_SPINLOCK(ratelimit_lock);
- static unsigned long toks = 10 * 5 * HZ;
- static unsigned long last_msg;
- static int missed;
unsigned long flags;
unsigned long now = jiffies;

spin_lock_irqsave(&ratelimit_lock, flags);
- toks += now - last_msg;
- last_msg = now;
- if (toks > (ratelimit_burst * ratelimit_jiffies))
- toks = ratelimit_burst * ratelimit_jiffies;
- if (toks >= ratelimit_jiffies) {
- int lost = missed;
-
- missed = 0;
- toks -= ratelimit_jiffies;
+ state->toks += now - state->last_jiffies;
+ /* Reset limiting if tunables changed */
+ if ((state->limit_jiffies != ratelimit_jiffies) ||
+ (state->limit_burst != ratelimit_burst)) {
+ state->toks = ratelimit_burst * ratelimit_jiffies;
+ state->limit_jiffies = ratelimit_jiffies;
+ state->limit_burst = ratelimit_burst;
+ }
+ state->last_jiffies = now;
+ if (state->toks > (ratelimit_burst * ratelimit_jiffies))
+ state->toks = ratelimit_burst * ratelimit_jiffies;
+ if (state->toks >= ratelimit_jiffies) {
+ int lost = state->missed;
+ state->missed = 0;
+ state->toks -= ratelimit_jiffies;
spin_unlock_irqrestore(&ratelimit_lock, flags);
- if (lost)
- printk(KERN_WARNING "printk: %d messages
suppressed.\n", lost);
+ if (lost) {
+ printk(KERN_WARNING
+ "printk: %d %s%smessage%s suppressed.\n",
+ lost,
+ (state->facility == 0 ? "" :
state->facility),
+ (state->facility == 0 ? "" : " "),
+ (lost > 1 ? "s" : ""));
+ }
return 1;
}
- missed++;
+ state->missed++;
spin_unlock_irqrestore(&ratelimit_lock, flags);
return 0;
}
@@ -1280,8 +1290,18 @@ int printk_ratelimit_burst = 10;

int printk_ratelimit(void)
{
+ static struct printk_ratelimit_state limit_state = {
+ .toks = 10 * 5 * HZ,
+ .last_jiffies = 0,
+ .missed = 0,
+ .limit_jiffies = 5 * HZ,
+ .limit_burst = 10,
+ .facility = 0
+ };
+
return __printk_ratelimit(printk_ratelimit_jiffies,
- printk_ratelimit_burst);
+ printk_ratelimit_burst,
+ &limit_state);
}
EXPORT_SYMBOL(printk_ratelimit);


2008-02-21 06:31:55

by David Miller

[permalink] [raw]
Subject: Re: printk_ratelimit and net_ratelimit conflict and tunable behavior

From: "Hawkes Steve-FSH016" <[email protected]>
Date: Tue, 19 Feb 2008 15:30:51 -0600

[ netdev CC:'d ]

> The printk_ratelimit() and net_ratelimit() functions are coupled and
> interfere with each other. Each has their own tunable parameters to
> control their respective rate limiting feature, but they share common
> state variables, causing the rate limiting to behave in an unexpected
> fashion when the tunables for each are set to different values.
>
> Also, changes to rate limiting tunable parameters do not always take
> effect
> properly since state is not recomputed when changes occur. For example,
> if
> the ratelimit_burst tunable value is increased while rate limiting
> is occurring, the change doesn't take full effect until at least enough
> time between messages occurs so that the toks value reaches
> ratelimit_burst * ratelimit_jiffies. This can result in messages being
> suppressed when they should be allowed.

This looks fine to me, please provide a proper "Signed-off-by: " as
described in linux/Documentation/SubmittingPatches

Thanks.

> diff -Naup OLD/include/linux/kernel.h NEW/include/linux/kernel.h
> --- OLD/include/linux/kernel.h 2008-02-19 10:02:07.461496000 -0600
> +++ NEW/include/linux/kernel.h 2008-02-19 10:45:32.858306000 -0600
> @@ -196,8 +196,20 @@ static inline int log_buf_copy(char *des
>
> unsigned long int_sqrt(unsigned long);
>
> +struct printk_ratelimit_state
> +{
> + unsigned long toks;
> + unsigned long last_jiffies;
> + int missed;
> + int limit_jiffies;
> + int limit_burst;
> + char const *facility;
> +};
> +
> +extern int __printk_ratelimit(int ratelimit_jiffies,
> + int ratelimit_burst,
> + struct printk_ratelimit_state *state);
> extern int printk_ratelimit(void);
> -extern int __printk_ratelimit(int ratelimit_jiffies, int
> ratelimit_burst);
> extern bool printk_timed_ratelimit(unsigned long *caller_jiffies,
> unsigned int interval_msec);
>
> diff -Naup OLD/net/core/utils.c NEW/net/core/utils.c
> --- OLD/net/core/utils.c 2008-02-19 10:01:26.442370000 -0600
> +++ NEW/net/core/utils.c 2008-02-19 10:46:45.026731000 -0600
> @@ -41,7 +41,18 @@ EXPORT_SYMBOL(net_msg_warn);
> */
> int net_ratelimit(void)
> {
> - return __printk_ratelimit(net_msg_cost, net_msg_burst);
> + static struct printk_ratelimit_state limit_state = {
> + .toks = 10 * 5 * HZ,
> + .last_jiffies = 0,
> + .missed = 0,
> + .limit_jiffies = 5 * HZ,
> + .limit_burst = 10,
> + .facility = "net"
> + };
> +
> + return __printk_ratelimit(net_msg_cost,
> + net_msg_burst,
> + &limit_state);
> }
> EXPORT_SYMBOL(net_ratelimit);
>
> diff -Naup OLD/kernel/printk.c NEW/kernel/print.c
> --- OLD/kernel/printk.c 2008-02-19 10:00:47.359068000 -0600
> +++ NEW/kernel/printk.c 2008-02-19 10:46:30.748743000 -0600
> @@ -1236,37 +1236,47 @@ void tty_write_message(struct tty_struct
> }
>
> /*
> - * printk rate limiting, lifted from the networking subsystem.
> + * printk rate limiting.
> *
> - * This enforces a rate limit: not more than one kernel message
> - * every printk_ratelimit_jiffies to make a denial-of-service
> - * attack impossible.
> + * This enforces a rate limit to mitigate denial-of-service attacks:
> + * not more than ratelimit_burst messages every ratelimit_jiffies.
> */
> -int __printk_ratelimit(int ratelimit_jiffies, int ratelimit_burst)
> +int __printk_ratelimit(int ratelimit_jiffies,
> + int ratelimit_burst,
> + struct printk_ratelimit_state *state)
> {
> static DEFINE_SPINLOCK(ratelimit_lock);
> - static unsigned long toks = 10 * 5 * HZ;
> - static unsigned long last_msg;
> - static int missed;
> unsigned long flags;
> unsigned long now = jiffies;
>
> spin_lock_irqsave(&ratelimit_lock, flags);
> - toks += now - last_msg;
> - last_msg = now;
> - if (toks > (ratelimit_burst * ratelimit_jiffies))
> - toks = ratelimit_burst * ratelimit_jiffies;
> - if (toks >= ratelimit_jiffies) {
> - int lost = missed;
> -
> - missed = 0;
> - toks -= ratelimit_jiffies;
> + state->toks += now - state->last_jiffies;
> + /* Reset limiting if tunables changed */
> + if ((state->limit_jiffies != ratelimit_jiffies) ||
> + (state->limit_burst != ratelimit_burst)) {
> + state->toks = ratelimit_burst * ratelimit_jiffies;
> + state->limit_jiffies = ratelimit_jiffies;
> + state->limit_burst = ratelimit_burst;
> + }
> + state->last_jiffies = now;
> + if (state->toks > (ratelimit_burst * ratelimit_jiffies))
> + state->toks = ratelimit_burst * ratelimit_jiffies;
> + if (state->toks >= ratelimit_jiffies) {
> + int lost = state->missed;
> + state->missed = 0;
> + state->toks -= ratelimit_jiffies;
> spin_unlock_irqrestore(&ratelimit_lock, flags);
> - if (lost)
> - printk(KERN_WARNING "printk: %d messages
> suppressed.\n", lost);
> + if (lost) {
> + printk(KERN_WARNING
> + "printk: %d %s%smessage%s suppressed.\n",
> + lost,
> + (state->facility == 0 ? "" :
> state->facility),
> + (state->facility == 0 ? "" : " "),
> + (lost > 1 ? "s" : ""));
> + }
> return 1;
> }
> - missed++;
> + state->missed++;
> spin_unlock_irqrestore(&ratelimit_lock, flags);
> return 0;
> }
> @@ -1280,8 +1290,18 @@ int printk_ratelimit_burst = 10;
>
> int printk_ratelimit(void)
> {
> + static struct printk_ratelimit_state limit_state = {
> + .toks = 10 * 5 * HZ,
> + .last_jiffies = 0,
> + .missed = 0,
> + .limit_jiffies = 5 * HZ,
> + .limit_burst = 10,
> + .facility = 0
> + };
> +
> return __printk_ratelimit(printk_ratelimit_jiffies,
> - printk_ratelimit_burst);
> + printk_ratelimit_burst,
> + &limit_state);
> }
> EXPORT_SYMBOL(printk_ratelimit);
>
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/

2008-02-21 07:01:23

by Joe Perches

[permalink] [raw]
Subject: Re: printk_ratelimit and net_ratelimit conflict and tunable behavior

On Wed, 2008-02-20 at 22:32 -0800, David Miller wrote:
> > + if (lost) {
> > + printk(KERN_WARNING
> > + "printk: %d %s%smessage%s suppressed.\n",
> > + lost,
> > + (state->facility == 0 ? "" :
> > state->facility),
> > + (state->facility == 0 ? "" : " "),
> > + (lost > 1 ? "s" : ""));
> > + }
> > return 1;
> > }

This compares a pointer to 0.

How about something like:

if (lost)
pr_warn("printk: %s suppressed message count: %d\n",
state->facility ? : "ratelimit", lost);

> > - missed++;
> > + state->missed++;
> > spin_unlock_irqrestore(&ratelimit_lock, flags);
> > return 0;
> > }
> > @@ -1280,8 +1290,18 @@ int printk_ratelimit_burst = 10;
> >
> > int printk_ratelimit(void)
> > {
> > + static struct printk_ratelimit_state limit_state = {
> > + .toks = 10 * 5 * HZ,
> > + .last_jiffies = 0,
> > + .missed = 0,
> > + .limit_jiffies = 5 * HZ,
> > + .limit_burst = 10,
> > + .facility = 0
> > + };
> > +

.facility = NULL

2008-02-25 15:47:29

by Hawkes Steve-FSH016

[permalink] [raw]
Subject: RE: printk_ratelimit and net_ratelimit conflict and tunable behavior

Joe Perches wrote:
>
> On Wed, 2008-02-20 at 22:32 -0800, David Miller wrote:
> > > + if (lost) {
> > > + printk(KERN_WARNING
> > > + "printk: %d %s%smessage%s suppressed.\n",
> > > + lost,
> > > + (state->facility == 0 ? "" :
> > > state->facility),
> > > + (state->facility == 0 ? "" : " "),
> > > + (lost > 1 ? "s" : ""));
> > > + }
> > > return 1;
> > > }
>
> This compares a pointer to 0.
>
> How about something like:
>
> if (lost)
> pr_warn("printk: %s suppressed message count: %d\n",
> state->facility ? : "ratelimit", lost);
>
> > > - missed++;
> > > + state->missed++;
> > > spin_unlock_irqrestore(&ratelimit_lock, flags);
> > > return 0;
> > > }
> > > @@ -1280,8 +1290,18 @@ int printk_ratelimit_burst = 10;
> > >
> > > int printk_ratelimit(void)
> > > {
> > > + static struct printk_ratelimit_state limit_state = {
> > > + .toks = 10 * 5 * HZ,
> > > + .last_jiffies = 0,
> > > + .missed = 0,
> > > + .limit_jiffies = 5 * HZ,
> > > + .limit_burst = 10,
> > > + .facility = 0
> > > + };
> > > +
>
> .facility = NULL

How about this?

Signed-off-by: Steve Hawkes <[email protected]>

diff -uprN linux-2.6.24/include/linux/kernel.h
linux-2.6.24-printk_ratelimit/include/linux/kernel.h
--- linux-2.6.24/include/linux/kernel.h 2008-01-24 16:58:37.000000000
-0600
+++ linux-2.6.24-printk_ratelimit/include/linux/kernel.h
2008-02-21 11:20:41.751197312 -0600
@@ -196,8 +196,19 @@ static inline int log_buf_copy(char *des

unsigned long int_sqrt(unsigned long);

+struct printk_ratelimit_state
+{
+ unsigned long toks;
+ unsigned long last_jiffies;
+ int missed;
+ int limit_jiffies;
+ int limit_burst;
+ char const *facility;
+};
+
extern int printk_ratelimit(void);
-extern int __printk_ratelimit(int ratelimit_jiffies, int
ratelimit_burst);
+extern int __printk_ratelimit(int ratelimit_jiffies, int
ratelimit_burst,
+ struct printk_ratelimit_state *state);
extern bool printk_timed_ratelimit(unsigned long *caller_jiffies,
unsigned int interval_msec);

diff -uprN linux-2.6.24/kernel/printk.c
linux-2.6.24-printk_ratelimit/kernel/printk.c
--- linux-2.6.24/kernel/printk.c 2008-01-24 16:58:37.000000000
-0600
+++ linux-2.6.24-printk_ratelimit/kernel/printk.c 2008-02-21
11:22:27.442319625 -0600
@@ -1238,35 +1238,41 @@ void tty_write_message(struct tty_struct
/*
* printk rate limiting, lifted from the networking subsystem.
*
- * This enforces a rate limit: not more than one kernel message
- * every printk_ratelimit_jiffies to make a denial-of-service
- * attack impossible.
+ * This enforces a rate limit to mitigate denial-of-service attacks:
+ * not more than ratelimit_burst messages every ratelimit_jiffies.
*/
-int __printk_ratelimit(int ratelimit_jiffies, int ratelimit_burst)
+int __printk_ratelimit(int ratelimit_jiffies,
+ int ratelimit_burst,
+ struct printk_ratelimit_state *state)
{
static DEFINE_SPINLOCK(ratelimit_lock);
- static unsigned long toks = 10 * 5 * HZ;
- static unsigned long last_msg;
- static int missed;
unsigned long flags;
unsigned long now = jiffies;

spin_lock_irqsave(&ratelimit_lock, flags);
- toks += now - last_msg;
- last_msg = now;
- if (toks > (ratelimit_burst * ratelimit_jiffies))
- toks = ratelimit_burst * ratelimit_jiffies;
- if (toks >= ratelimit_jiffies) {
- int lost = missed;
-
- missed = 0;
- toks -= ratelimit_jiffies;
+ state->toks += now - state->last_jiffies;
+ /* Reset limiting if tunables changed */
+ if ((state->limit_jiffies != ratelimit_jiffies) ||
+ (state->limit_burst != ratelimit_burst)) {
+ state->toks = ratelimit_burst * ratelimit_jiffies;
+ state->limit_jiffies = ratelimit_jiffies;
+ state->limit_burst = ratelimit_burst;
+ }
+ state->last_jiffies = now;
+ if (state->toks > (ratelimit_burst * ratelimit_jiffies))
+ state->toks = ratelimit_burst * ratelimit_jiffies;
+ if (state->toks >= ratelimit_jiffies) {
+ int lost = state->missed;
+ state->missed = 0;
+ state->toks -= ratelimit_jiffies;
spin_unlock_irqrestore(&ratelimit_lock, flags);
- if (lost)
- printk(KERN_WARNING "printk: %d messages
suppressed.\n", lost);
+ if (lost) {
+ pr_warning("%s ratelimit suppressed message
count: %d\n",
+ state->facility, lost);
+ }
return 1;
}
- missed++;
+ state->missed++;
spin_unlock_irqrestore(&ratelimit_lock, flags);
return 0;
}
@@ -1280,8 +1286,17 @@ int printk_ratelimit_burst = 10;

int printk_ratelimit(void)
{
+ static struct printk_ratelimit_state limit_state = {
+ .toks = 10 * 5 * HZ,
+ .last_jiffies = 0,
+ .missed = 0,
+ .limit_jiffies = 5 * HZ,
+ .limit_burst = 10,
+ .facility = "printk"
+ };
+
return __printk_ratelimit(printk_ratelimit_jiffies,
- printk_ratelimit_burst);
+ printk_ratelimit_burst, &limit_state);
}
EXPORT_SYMBOL(printk_ratelimit);

diff -uprN linux-2.6.24/net/core/utils.c
linux-2.6.24-printk_ratelimit/net/core/utils.c
--- linux-2.6.24/net/core/utils.c 2008-01-24 16:58:37.000000000
-0600
+++ linux-2.6.24-printk_ratelimit/net/core/utils.c 2008-02-21
11:03:44.644337698 -0600
@@ -41,7 +41,16 @@ EXPORT_SYMBOL(net_msg_warn);
*/
int net_ratelimit(void)
{
- return __printk_ratelimit(net_msg_cost, net_msg_burst);
+ static struct printk_ratelimit_state limit_state = {
+ .toks = 10 * 5 * HZ,
+ .last_jiffies = 0,
+ .missed = 0,
+ .limit_jiffies = 5 * HZ,
+ .limit_burst = 10,
+ .facility = "net"
+ };
+
+ return __printk_ratelimit(net_msg_cost, net_msg_burst,
&limit_state);
}
EXPORT_SYMBOL(net_ratelimit);

2008-02-25 20:01:39

by David Miller

[permalink] [raw]
Subject: Re: printk_ratelimit and net_ratelimit conflict and tunable behavior

From: "Hawkes Steve-FSH016" <[email protected]>
Date: Mon, 25 Feb 2008 09:47:11 -0600

> > .facility = NULL
>
> How about this?

Actually, for compile time initializations, setting
anything to zero is superfluous and by convention
is not therefore explicitly done in the sources.

2008-02-25 20:14:20

by Joe Perches

[permalink] [raw]
Subject: RE: printk_ratelimit and net_ratelimit conflict and tunable behavior

On Mon, 2008-02-25 at 09:47 -0600, Hawkes Steve-FSH016 wrote:
> How about this?

line wrapped, but seems better.

> Signed-off-by: Steve Hawkes <[email protected]>
>
> diff -uprN linux-2.6.24/include/linux/kernel.h
> linux-2.6.24-printk_ratelimit/include/linux/kernel.h
> --- linux-2.6.24/include/linux/kernel.h 2008-01-24 16:58:37.000000000
> + * This enforces a rate limit to mitigate denial-of-service attacks:
> + * not more than ratelimit_burst messages every ratelimit_jiffies.
> */
> -int __printk_ratelimit(int ratelimit_jiffies, int ratelimit_burst)
> +int __printk_ratelimit(int ratelimit_jiffies,
> + int ratelimit_burst,
> + struct printk_ratelimit_state *state)

I think the value of in-place tunables is low.
I'd remove that bit and use the struct printk_ratelimit_state.

David Miller points out that struct initializations to 0 or NULL
are not necessary.