[PATCH v2(sorta)] Unexpected-continuation-frame-printk flood avoidance

[PATCH v2(sorta)] Unexpected-continuation-frame-printk flood avoidance

[Gregory M. Turner]

Mitigation for those with floods of:

  Bluetooth: Unexpected Continuation Frame (len 0)

in their logs.  The underlying cause of this is still far from crystal clear
(at least, not to me), but, anyhow, I'm sold on Marcel's advice to solve this
by placing my dongle in the garbage.

Previously I suggested dropping the printk entirely but ratelimiting is
better, since the printk is not wrong (or, if it were wrong, this would
at least be indicative of a problem elsewhere).

[PATCH v2(sorta) 1/2] bluetooth: Add BT_{INFO,ERR,DBG}_RATELIMITED

[Gregory M. Turner]

Add ratelimited versions of the BT_{INFO,ERR,DBG} printk macros.

The assymetry with the existing _INFO and _ERR macros is because,
afaics, those are special-cased as an object-file-size optimization.
Duplicating that for the _RATELIMITED versions would clearly be a
deoptimization until they got a few more consumers (currently only a
single consumer is planned).

Signed-off-by: Gregory M. Turner <gmt@be-evil.net>
---
 include/net/bluetooth/bluetooth.h | 9 ++++++---
 1 file changed, 6 insertions(+), 3 deletions(-)

diff --git a/include/net/bluetooth/bluetooth.h b/include/net/bluetooth/bluetooth.h
index e00455a..ec321f9 100644
--- a/include/net/bluetooth/bluetooth.h
+++ b/include/net/bluetooth/bluetooth.h
@@ -124,9 +124,12 @@ void bt_info(const char *fmt, ...);
 __printf(1, 2)
 void bt_err(const char *fmt, ...);
 
-#define BT_INFO(fmt, ...)	bt_info(fmt "\n", ##__VA_ARGS__)
-#define BT_ERR(fmt, ...)	bt_err(fmt "\n", ##__VA_ARGS__)
-#define BT_DBG(fmt, ...)	pr_debug(fmt "\n", ##__VA_ARGS__)
+#define BT_INFO(fmt, ...)		bt_info(fmt "\n", ##__VA_ARGS__)
+#define BT_INFO_RATELIMITED(fmt, ...)	pr_info_ratelimited(fmt "\n", ##__VA_ARGS__)
+#define BT_ERR(fmt, ...)		bt_err(fmt "\n", ##__VA_ARGS__)
+#define BT_ERR_RATELIMITED(fmt, ...)	pr_err_ratelimited(fmt "\n", ##__VA_ARGS__)
+#define BT_DBG(fmt, ...)		pr_debug(fmt "\n", ##__VA_ARGS__)
+#define BT_DBG_RATELIMITED(fmt, ...)	pr_debug_ratelimited(fmt "\n", ##__VA_ARGS__)
 
 /* Connection and socket states */
 enum {
-- 
2.3.0

Re: [PATCH v2(sorta) 1/2] bluetooth: Add BT_{INFO,ERR,DBG}_RATELIMITED

[Marcel Holtmann]

Hi Gregory,

> Add ratelimited versions of the BT_{INFO,ERR,DBG} printk macros.
> 
> The assymetry with the existing _INFO and _ERR macros is because,
> afaics, those are special-cased as an object-file-size optimization.
> Duplicating that for the _RATELIMITED versions would clearly be a
> deoptimization until they got a few more consumers (currently only a
> single consumer is planned).
> 
> Signed-off-by: Gregory M. Turner <gmt@be-evil.net>
> ---
> include/net/bluetooth/bluetooth.h | 9 ++++++---
> 1 file changed, 6 insertions(+), 3 deletions(-)
> 
> diff --git a/include/net/bluetooth/bluetooth.h b/include/net/bluetooth/bluetooth.h
> index e00455a..ec321f9 100644
> --- a/include/net/bluetooth/bluetooth.h
> +++ b/include/net/bluetooth/bluetooth.h
> @@ -124,9 +124,12 @@ void bt_info(const char *fmt, ...);
> __printf(1, 2)
> void bt_err(const char *fmt, ...);
> 
> -#define BT_INFO(fmt, ...)	bt_info(fmt "\n", ##__VA_ARGS__)
> -#define BT_ERR(fmt, ...)	bt_err(fmt "\n", ##__VA_ARGS__)
> -#define BT_DBG(fmt, ...)	pr_debug(fmt "\n", ##__VA_ARGS__)
> +#define BT_INFO(fmt, ...)		bt_info(fmt "\n", ##__VA_ARGS__)
> +#define BT_INFO_RATELIMITED(fmt, ...)	pr_info_ratelimited(fmt "\n", ##__VA_ARGS__)
> +#define BT_ERR(fmt, ...)		bt_err(fmt "\n", ##__VA_ARGS__)
> +#define BT_ERR_RATELIMITED(fmt, ...)	pr_err_ratelimited(fmt "\n", ##__VA_ARGS__)
> +#define BT_DBG(fmt, ...)		pr_debug(fmt "\n", ##__VA_ARGS__)
> +#define BT_DBG_RATELIMITED(fmt, ...)	pr_debug_ratelimited(fmt "\n", ##__VA_ARGS__)

I would prefer that you only introduce BT_ERR_RATELIMITED and we leave it at that. Since that is the only one we need anyway. And please do not re-indent the existing ones. Just keep them as they are.

Regards

Marcel

Re: [PATCH v2(sorta) 1/2] bluetooth: Add BT_{INFO,ERR,DBG}_RATELIMITED

[Greg Turner]

On Mon, Mar 2, 2015 at 5:07 PM, Marcel Holtmann <marcel@holtmann.org> wrote:
> Hi Gregory,
>
>> Add ratelimited versions of the BT_{INFO,ERR,DBG} printk macros.
>> [snip]

Oops, caught a nasty cold and forgot all about this.

Meanwhile, I've been running 3.1{8,9} stables with the v2(sorta)
patches in, where they seem to be working as advertised.

> I would prefer that you only introduce BT_ERR_RATELIMITED
> and we leave it at that. Since that is the only one we
> need anyway. And please do not re-indent the existing
> ones. Just keep them as they are.

Sure, I'll rev. & resubmit sometime soon{,-ish}.

-gmt

[PATCH v3 1/1] bluetooth: l2cap_core: ratelimit continuation frame printk

[gmt]

From: "Gregory M. Turner" <gmt@be-evil.net>

For ages, some(1) users, presumably with broken hardware or buggy
drivers, get storms of "Unexpected continuation frame (len 0)"
messages flooding their logs (but are otherwise able to scrape
by without resolving the underlying problem).  So, ratelimit this
printk.

(1)
me
https://bugs.launchpad.net/ubuntu/+source/bluetooth-alsa/+bug/192502
https://bugzilla.kernel.org/show_bug.cgi?id=11705
https://bugzilla.redhat.com/show_bug.cgi?id=450490
.
.
(just Google, I'm not making it up)

Signed-off-by: Gregory M. Turner <gmt@be-evil.net>
---
 include/net/bluetooth/bluetooth.h | 2 ++
 net/bluetooth/l2cap_core.c        | 2 +-
 2 files changed, 3 insertions(+), 1 deletion(-)

diff --git a/include/net/bluetooth/bluetooth.h b/include/net/bluetooth/bluetooth.h
index e00455a..4d47ef6 100644
--- a/include/net/bluetooth/bluetooth.h
+++ b/include/net/bluetooth/bluetooth.h
@@ -128,6 +128,8 @@ void bt_err(const char *fmt, ...);
 #define BT_ERR(fmt, ...)	bt_err(fmt "\n", ##__VA_ARGS__)
 #define BT_DBG(fmt, ...)	pr_debug(fmt "\n", ##__VA_ARGS__)
 
+#define BT_ERR_RATELIMITED(fmt, ...)	pr_err_ratelimited(fmt "\n", ##__VA_ARGS__)
+
 /* Connection and socket states */
 enum {
 	BT_CONNECTED = 1, /* Equal to TCP_ESTABLISHED to make net code happy */
diff --git a/net/bluetooth/l2cap_core.c b/net/bluetooth/l2cap_core.c
index 6ba33f9..7090aa0 100644
--- a/net/bluetooth/l2cap_core.c
+++ b/net/bluetooth/l2cap_core.c
@@ -7493,7 +7493,7 @@ int l2cap_recv_acldata(struct hci_conn *hcon, struct sk_buff *skb, u16 flags)
 		BT_DBG("Cont: frag len %d (expecting %d)", skb->len, conn->rx_len);
 
 		if (!conn->rx_len) {
-			BT_ERR("Unexpected continuation frame (len %d)", skb->len);
+			BT_ERR_RATELIMITED("Unexpected continuation frame (len %d)", skb->len);
 			l2cap_conn_unreliable(conn, ECOMM);
 			goto drop;
 		}
-- 
2.3.3

[PATCH v2(sorta) 2/2] bluetooth: l2cap_core: ratelimit continuation frame printk

[Gregory M. Turner]

Some(1) users with semi-broken dongles (?) get storms of "Unexpected
continuation frame (len 0)" messages flooding their logs.  So ratelimit
this printk.

(1)
https://bugs.launchpad.net/ubuntu/+source/bluetooth-alsa/+bug/192502
https://bugzilla.kernel.org/show_bug.cgi?id=11705
https://bugzilla.redhat.com/show_bug.cgi?id=450490

Signed-off-by: Gregory M. Turner <gmt@be-evil.net>
---
 net/bluetooth/l2cap_core.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/net/bluetooth/l2cap_core.c b/net/bluetooth/l2cap_core.c
index 6ba33f9..7090aa0 100644
--- a/net/bluetooth/l2cap_core.c
+++ b/net/bluetooth/l2cap_core.c
@@ -7493,7 +7493,7 @@ int l2cap_recv_acldata(struct hci_conn *hcon, struct sk_buff *skb, u16 flags)
 		BT_DBG("Cont: frag len %d (expecting %d)", skb->len, conn->rx_len);
 
 		if (!conn->rx_len) {
-			BT_ERR("Unexpected continuation frame (len %d)", skb->len);
+			BT_ERR_RATELIMITED("Unexpected continuation frame (len %d)", skb->len);
 			l2cap_conn_unreliable(conn, ECOMM);
 			goto drop;
 		}
-- 
2.3.0