mirror of https://lore.kernel.org/lkml/
 help / color / mirror / Atom feed
* [PATCH] Bluetooth: Add missing newline to bt_dev_{err,warn}_ratelimited()
@ 2026-10-06 21:21 Hitalo Souza
  2026-10-07 17:30 ` patchwork-bot+bluetooth
  0 siblings, 1 reply; 2+ messages in thread
From: Hitalo Souza @ 2026-10-06 21:21 UTC (permalink / raw)
  To: linux-bluetooth
  Cc: marcel, luiz.dentz, linux-kernel, michael.bommarito, Hitalo Souza

bt_dev_err_ratelimited() and bt_dev_warn_ratelimited() pass the format
string to bt_err_ratelimited()/bt_warn_ratelimited() without appending
a newline, unlike bt_dev_err() and bt_dev_warn(), which go through
BT_ERR()/BT_WARN() and add one. Only 2 of the 22 in-tree callers (both
in virtio_bt) put the newline in their own format string.

A printk record without a trailing newline is stored with prb_commit()
instead of prb_final_commit(), and readers of the log buffer (/dev/kmsg,
syslog) do not see it until it is finalized, which only happens when the
next record is reserved. These messages therefore stay invisible until
some unrelated message is printed, and journald, which timestamps a
record when it reads it, logs them with the time of that later message.

This was observed with a MediaTek MT7921 controller (USB 04ca:3802):
when an eSCO link is closed, the host still receives a few SCO packets
for the handle after Disconnection Complete, so hci_scodata_packet()
logs "SCO packet for unknown connection handle". Comparing the record's
kernel timestamp (_SOURCE_MONOTONIC_TIMESTAMP) with the time journald
received it, over one capture:

  emitted       logged        delay
  15:36:52.896  15:37:00.214    7.3 s
  15:37:03.410  15:39:05.574  122.2 s
  15:39:05.574  15:39:12.506    6.9 s
  15:39:19.791  15:40:54.109   94.3 s
  15:41:22.021  15:41:24.647    2.6 s

Each message showed up together with the next kernel message; the 94 s
one looked as if it had been logged in the middle of a later, healthy
eSCO connection.

bt_dev_err_ratelimited() lost its newline in commit 657cc646475b
("Bluetooth: Remove usage of BT_ERR_RATELIMITED macro"), which replaced
BT_ERR_RATELIMITED(), the variant that appended "\n", with a direct call
to bt_err_ratelimited(). bt_dev_warn_ratelimited() never had one.

Append the newline in both macros, as BT_ERR() and BT_WARN() do, and
drop it from the two virtio_bt format strings so that their messages do
not gain an empty line.

Fixes: 36278a5d4d35 ("Bluetooth: Adding a bt_dev_warn_ratelimited macro.")
Fixes: 657cc646475b ("Bluetooth: Remove usage of BT_ERR_RATELIMITED macro")
Assisted-by: Claude:claude-opus-5-5
Signed-off-by: Hitalo Souza <enghitalo@gmail.com>
---
Testing:

- Booted bluetooth-next (base c85976511aa9) with and without this patch
  in QEMU/KVM (x86_64 defconfig + kvm_guest.config, BT=y, BT_HCIVHCI=y).
  A small userspace program emulates a BR/EDR controller over hci_vhci,
  brings it up with HCIDEVUP and injects one SCO packet for handle
  0x0123, which has no connection, so hci_scodata_packet() logs through
  bt_dev_err_ratelimited(). /dev/kmsg is then read 1 s and 10 s later,
  and once more after writing another record to /dev/kmsg:

                         without patch   with patch
    after 1 s            not visible     visible
    after 10 s           not visible     visible
    after next printk    visible         visible

  Without the patch the record (seq 411, 5.730471) only became readable
  together with the next one (seq 412, 15.733219).

- Same result on 7.1.13 (Manjaro) on real hardware, with a throwaway
  module that calls bt_dev_err_ratelimited(NULL, ...) and the same macro
  with "\n" appended.

- GCC 16.2.1, W=1, net/bluetooth/ and drivers/bluetooth/: x86_64
  defconfig + BT, BT_HCIBTUSB{,_MTK,_QCOM}, BT_VIRTIO; x86_64
  allmodconfig (WERROR=y); i386 defconfig + the same options. No
  warnings (the x86_64 defconfig build was also clean without the
  patch). allnoconfig vmlinux builds (Bluetooth is off there; two
  unrelated W=1 warnings in arch/x86/mm/pgtable.c and
  fs/proc/proc_sysctl.c). Checked in the objects that all 22 format
  strings end with exactly one newline.

- LLVM 22.1.8 (LLVM=1), W=1, same directories and options: arm64
  defconfig, arm multi_v7_defconfig, riscv defconfig and powerpc
  ppc64_defconfig (big-endian). No warnings.

- sparse v0.6.5-rc1 on the same directories: the same 16 reports before
  and after, none on the lines touched here.

The change, this changelog and the test harness were prepared with an
AI assistant (Claude, see Assisted-by) while debugging HFP problems with
an MT7921 adapter: it noticed the delayed log lines by comparing
journald's receive time with the kernel timestamps, traced them to the
missing newline, wrote the patch and the reproducers and ran the checks
above.

 drivers/bluetooth/virtio_bt.c     | 4 ++--
 include/net/bluetooth/bluetooth.h | 4 ++--
 2 files changed, 4 insertions(+), 4 deletions(-)

diff --git a/drivers/bluetooth/virtio_bt.c b/drivers/bluetooth/virtio_bt.c
index 8c55b538d..638140406 100644
--- a/drivers/bluetooth/virtio_bt.c
+++ b/drivers/bluetooth/virtio_bt.c
@@ -228,7 +228,7 @@ static void virtbt_rx_handle(struct virtio_bluetooth *vbt, struct sk_buff *skb)
 
 	if (skb->len < min_hdr) {
 		bt_dev_err_ratelimited(vbt->hdev,
-				       "rx pkt_type 0x%02x payload %u < hdr %zu\n",
+				       "rx pkt_type 0x%02x payload %u < hdr %zu",
 				       pkt_type, skb->len, min_hdr);
 		kfree_skb(skb);
 		return;
@@ -251,7 +251,7 @@ static void virtbt_rx_work(struct work_struct *work)
 
 	if (!len || len > VIRTBT_RX_BUF_SIZE) {
 		bt_dev_err_ratelimited(vbt->hdev,
-				       "rx reply len %u outside [1, %u]\n",
+				       "rx reply len %u outside [1, %u]",
 				       len, VIRTBT_RX_BUF_SIZE);
 		kfree_skb(skb);
 	} else {
diff --git a/include/net/bluetooth/bluetooth.h b/include/net/bluetooth/bluetooth.h
index b624da502..cd9189244 100644
--- a/include/net/bluetooth/bluetooth.h
+++ b/include/net/bluetooth/bluetooth.h
@@ -296,9 +296,9 @@ void bt_err_ratelimited(const char *fmt, ...);
 	BT_DBG("%s: " fmt, bt_dev_name(hdev), ##__VA_ARGS__)
 
 #define bt_dev_warn_ratelimited(hdev, fmt, ...)			\
-	bt_warn_ratelimited("%s: " fmt, bt_dev_name(hdev), ##__VA_ARGS__)
+	bt_warn_ratelimited("%s: " fmt "\n", bt_dev_name(hdev), ##__VA_ARGS__)
 #define bt_dev_err_ratelimited(hdev, fmt, ...)			\
-	bt_err_ratelimited("%s: " fmt, bt_dev_name(hdev), ##__VA_ARGS__)
+	bt_err_ratelimited("%s: " fmt "\n", bt_dev_name(hdev), ##__VA_ARGS__)
 
 /* Connection and socket states */
 enum bt_sock_state {

base-commit: c85976511aa95b5ba68b57b0b3c87c67f3cedcce
-- 
2.55.0


^ permalink raw reply	[flat|nested] 2+ messages in thread

* Re: [PATCH] Bluetooth: Add missing newline to bt_dev_{err,warn}_ratelimited()
  2026-10-06 21:21 [PATCH] Bluetooth: Add missing newline to bt_dev_{err,warn}_ratelimited() Hitalo Souza
@ 2026-10-07 17:30 ` patchwork-bot+bluetooth
  0 siblings, 0 replies; 2+ messages in thread
From: patchwork-bot+bluetooth @ 2026-10-07 17:30 UTC (permalink / raw)
  To: Hitalo Souza
  Cc: linux-bluetooth, marcel, luiz.dentz, linux-kernel, michael.bommarito

Hello:

This patch was applied to bluetooth/bluetooth-next.git (master)
by Luiz Augusto von Dentz <luiz.von.dentz@intel.com>:

On Tue,  6 Oct 2026 17:21:42 -0400 you wrote:
> bt_dev_err_ratelimited() and bt_dev_warn_ratelimited() pass the format
> string to bt_err_ratelimited()/bt_warn_ratelimited() without appending
> a newline, unlike bt_dev_err() and bt_dev_warn(), which go through
> BT_ERR()/BT_WARN() and add one. Only 2 of the 22 in-tree callers (both
> in virtio_bt) put the newline in their own format string.
> 
> A printk record without a trailing newline is stored with prb_commit()
> instead of prb_final_commit(), and readers of the log buffer (/dev/kmsg,
> syslog) do not see it until it is finalized, which only happens when the
> next record is reserved. These messages therefore stay invisible until
> some unrelated message is printed, and journald, which timestamps a
> record when it reads it, logs them with the time of that later message.
> 
> [...]

Here is the summary with links:
  - Bluetooth: Add missing newline to bt_dev_{err,warn}_ratelimited()
    https://git.kernel.org/bluetooth/bluetooth-next/c/f3d041ec63f7

You are awesome, thank you!
-- 
Deet-doot-dot, I am a bot.
https://korg.docs.kernel.org/patchwork/pwbot.html



^ permalink raw reply	[flat|nested] 2+ messages in thread

end of thread, other threads:[~2026-10-07 17:30 UTC | newest]

Thread overview: 2+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2026-10-06 21:21 [PATCH] Bluetooth: Add missing newline to bt_dev_{err,warn}_ratelimited() Hitalo Souza
2026-10-07 17:30 ` patchwork-bot+bluetooth

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox

all inboxes | Powered by JetHome®