* [RFC PATCH 0/3] Bluetooth: add transmission latency tracking for ISO & L2CAP
@ 2024-02-28 20:03 Pauli Virtanen
2024-02-28 20:03 ` [RFC PATCH 1/3] Bluetooth: add transmission latency tracking for ISO and ACL Pauli Virtanen
` (3 more replies)
0 siblings, 4 replies; 8+ messages in thread
From: Pauli Virtanen @ 2024-02-28 20:03 UTC (permalink / raw
To: linux-bluetooth; +Cc: Pauli Virtanen
Add ISO/L2CAP socket ioctl() BTGETTXINFO which informs the user how long
it took the kernel and controller to complete their sendmsg(), and how
many sendmsg() are in socket and controller queues.
This currently provides information of the latest packet only, in
principle there could be a ringbuffer containing few latest packets, not
clear if that would be useful.
These patches allow fixing / working around controller(?) issue where
two ISO streams in same group get desynchronized. Having accurate
knowledge of the packet queue lengths, user application can drop packets
if it detects the ISO streams are not in sync.
Pipewire side:
https://gitlab.freedesktop.org/pvir/pipewire/-/commits/iso-ts-test
With this change, https://github.com/bluez/bluez/issues/515 is more or
less fixed, and the sound server can figure out the total latency to
audio rendering (tx latency + transport latency + presentation delay).
For ISO, this can be changed to use LE Read ISO TX Sync, when the clock
and sequence number synchronization issues there are figured out, and a
quirk is added for controllers with nonfunctional implementation.
For the L2CAP latency, I'll need to think a bit more what is the audio
use case. Motivation was that AVDTP delay report values appear to be off
by ~0..40 ms compared to observed audio latency and this amount can vary
per connection and time, so not explained by unaccounted code
algorithmic delays etc. Currently it's not clear if there is relation to
TX side latency, so it may be down to receiver side implementation.
This needs a bit more work to figure out, but the L2CAP patch is anyway
here. Due to the possible fragmentation in ISO sendmsg(), it seems we
anyway need the tx_info_queue thing and can't easily do it by counting
packets, and L2CAP required part is small addition on top of that.
TBD: iso-tester / l2cap-tester tests
Pauli Virtanen (3):
Bluetooth: add transmission latency tracking for ISO and ACL
Bluetooth: ISO: add new ioctl() for reading tx latency
Bluetooth: L2CAP: add new ioctl() for reading tx latency
include/net/bluetooth/bluetooth.h | 39 +++++++++++
include/net/bluetooth/hci_core.h | 30 ++++++++
net/bluetooth/hci_conn.c | 110 +++++++++++++++++++++++++++++-
net/bluetooth/hci_core.c | 14 ++++
net/bluetooth/hci_event.c | 66 ++++++++++++++++++
net/bluetooth/iso.c | 58 ++++++++++++++--
net/bluetooth/l2cap_core.c | 12 ++++
net/bluetooth/l2cap_sock.c | 50 +++++++++++++-
8 files changed, 372 insertions(+), 7 deletions(-)
--
2.44.0
^ permalink raw reply [flat|nested] 8+ messages in thread
* [RFC PATCH 1/3] Bluetooth: add transmission latency tracking for ISO and ACL
2024-02-28 20:03 [RFC PATCH 0/3] Bluetooth: add transmission latency tracking for ISO & L2CAP Pauli Virtanen
@ 2024-02-28 20:03 ` Pauli Virtanen
2024-02-28 20:34 ` Bluetooth: add transmission latency tracking for ISO & L2CAP bluez.test.bot
2024-02-28 20:03 ` [RFC PATCH 2/3] Bluetooth: ISO: add new ioctl() for reading tx latency Pauli Virtanen
` (2 subsequent siblings)
3 siblings, 1 reply; 8+ messages in thread
From: Pauli Virtanen @ 2024-02-28 20:03 UTC (permalink / raw
To: linux-bluetooth; +Cc: Pauli Virtanen
Add mechanism to track specific skbs from socket to controller packet
completion.
This will be used to allow users submitting packets to sockets, to find
for the latest completed packet: the total socket+controller queue
length (in packets they submitted), controller packet completion timing,
and current total transmission latency.
This handles fragmentation of user-submitted packets and flow control in
L2CAP, which make raw skb queue lengths not informative to the user, and
does not change skb life cycle.
Implementation:
Sockets may mark selected skbs. When controller reports the
corresponding packet completed, information in struct tx_latency in the
corresponding hci_conn or hci_chan is updated.
Add struct tx_latency to hci_conn and hci_chan, to track last completed
packet status.
Add hci_tx_info_queue to each hci_conn, and use it to track which
packets they sent to controller. In packet completion event, pop info
from the queues to find if the packet had marked skb and which hci_chan
it came from.
Allow safe concurrent reading of struct tx_latency.
Signed-off-by: Pauli Virtanen <pav@iki.fi>
---
include/net/bluetooth/bluetooth.h | 2 +
include/net/bluetooth/hci_core.h | 30 ++++++++
net/bluetooth/hci_conn.c | 110 +++++++++++++++++++++++++++++-
net/bluetooth/hci_core.c | 14 ++++
net/bluetooth/hci_event.c | 66 ++++++++++++++++++
5 files changed, 221 insertions(+), 1 deletion(-)
diff --git a/include/net/bluetooth/bluetooth.h b/include/net/bluetooth/bluetooth.h
index 7ffa8c192c3f..f6bdd040adaa 100644
--- a/include/net/bluetooth/bluetooth.h
+++ b/include/net/bluetooth/bluetooth.h
@@ -462,6 +462,8 @@ struct bt_skb_cb {
u8 pkt_type;
u8 force_active;
u16 expect;
+ u16 user_sn;
+ u8 have_user_sn:1;
u8 incoming:1;
u8 pkt_status:2;
union {
diff --git a/include/net/bluetooth/hci_core.h b/include/net/bluetooth/hci_core.h
index 56fb42df44a3..e84a37c1e8b1 100644
--- a/include/net/bluetooth/hci_core.h
+++ b/include/net/bluetooth/hci_core.h
@@ -29,6 +29,7 @@
#include <linux/idr.h>
#include <linux/leds.h>
#include <linux/rculist.h>
+#include <linux/seqlock.h>
#include <net/bluetooth/hci.h>
#include <net/bluetooth/hci_sync.h>
@@ -267,6 +268,26 @@ struct adv_info {
struct delayed_work rpa_expired_cb;
};
+struct tx_latency {
+ seqcount_t seq;
+ struct {
+ ktime_t time;
+ __s64 offset;
+ unsigned int queue;
+ } now;
+ __u16 sn;
+};
+
+struct tx_info_queue {
+ struct {
+ __u16 sn;
+ void *data;
+ } *info;
+ unsigned int size;
+ unsigned int head;
+ unsigned int num;
+};
+
#define HCI_MAX_ADV_INSTANCES 5
#define HCI_DEFAULT_ADV_DURATION 2
@@ -746,6 +767,9 @@ struct hci_conn {
struct bt_iso_qos iso_qos;
unsigned long flags;
+ struct tx_latency tx_latency;
+ struct tx_info_queue tx_info_queue;
+
enum conn_reasons conn_reason;
__u8 abort_reason;
@@ -803,6 +827,7 @@ struct hci_chan {
unsigned int sent;
__u8 state;
bool amp;
+ struct tx_latency tx_latency;
};
struct hci_conn_params {
@@ -1546,6 +1571,11 @@ void hci_conn_enter_active_mode(struct hci_conn *conn, __u8 force_active);
void hci_conn_failed(struct hci_conn *conn, u8 status);
u8 hci_conn_set_handle(struct hci_conn *conn, u16 handle);
+void hci_conn_tx_info_push(struct hci_conn *conn, void *ptr, __u16 sn);
+void *hci_conn_tx_info_pop(struct hci_conn *conn, __u16 *sn);
+void hci_mark_tx_latency(struct tx_latency *tx, struct sk_buff *skb);
+void hci_copy_tx_latency(struct tx_latency *dst, struct tx_latency *src);
+
/*
* hci_conn_get() and hci_conn_put() are used to control the life-time of an
* "hci_conn" object. They do not guarantee that the hci_conn object is running,
diff --git a/net/bluetooth/hci_conn.c b/net/bluetooth/hci_conn.c
index 3ad74f76983b..2c557eb63b93 100644
--- a/net/bluetooth/hci_conn.c
+++ b/net/bluetooth/hci_conn.c
@@ -138,6 +138,12 @@ void hci_connect_le_scan_cleanup(struct hci_conn *conn, u8 status)
hci_update_passive_scan(hdev);
}
+static void hci_conn_tx_info_cleanup(struct hci_conn *conn)
+{
+ kfree(conn->tx_info_queue.info);
+ conn->tx_info_queue.info = NULL;
+}
+
static void hci_conn_cleanup(struct hci_conn *conn)
{
struct hci_dev *hdev = conn->hdev;
@@ -158,6 +164,8 @@ static void hci_conn_cleanup(struct hci_conn *conn)
if (conn->cleanup)
conn->cleanup(conn);
+ hci_conn_tx_info_cleanup(conn);
+
if (conn->type == SCO_LINK || conn->type == ESCO_LINK) {
switch (conn->setting & SCO_AIRMODE_MASK) {
case SCO_AIRMODE_CVSD:
@@ -904,6 +912,39 @@ static int hci_conn_hash_alloc_unset(struct hci_dev *hdev)
U16_MAX, GFP_ATOMIC);
}
+static int hci_conn_tx_info_init(struct hci_conn *conn)
+{
+ struct tx_info_queue *txq = &conn->tx_info_queue;
+ size_t size = 0;
+
+ switch (conn->type) {
+ case ISO_LINK:
+ size = conn->hdev->iso_pkts;
+ if (!size)
+ size = conn->hdev->le_pkts;
+ if (!size)
+ size = conn->hdev->acl_pkts;
+ break;
+ case ACL_LINK:
+ size = conn->hdev->acl_pkts;
+ break;
+ }
+
+ if (size) {
+ txq->info = kcalloc(size, sizeof(txq->info[0]), GFP_KERNEL);
+ if (!txq->info)
+ return -ENOMEM;
+ } else {
+ txq->info = NULL;
+ }
+
+ txq->size = size;
+ txq->head = 0;
+ txq->num = 0;
+
+ return 0;
+}
+
struct hci_conn *hci_conn_add(struct hci_dev *hdev, int type, bdaddr_t *dst,
u8 role, u16 handle)
{
@@ -932,6 +973,12 @@ struct hci_conn *hci_conn_add(struct hci_dev *hdev, int type, bdaddr_t *dst,
conn->max_tx_power = HCI_TX_POWER_INVALID;
conn->sync_handle = HCI_SYNC_HANDLE_INVALID;
+ seqcount_init(&conn->tx_latency.seq);
+ if (hci_conn_tx_info_init(conn) < 0) {
+ kfree(conn);
+ return NULL;
+ }
+
set_bit(HCI_CONN_POWER_SAVE, &conn->flags);
conn->disc_timeout = HCI_DISCONN_TIMEOUT;
@@ -1005,6 +1052,7 @@ struct hci_conn *hci_conn_add(struct hci_dev *hdev, int type, bdaddr_t *dst,
struct hci_conn *hci_conn_add_unset(struct hci_dev *hdev, int type,
bdaddr_t *dst, u8 role)
{
+ struct hci_conn *conn;
int handle;
bt_dev_dbg(hdev, "dst %pMR", dst);
@@ -1013,7 +1061,11 @@ struct hci_conn *hci_conn_add_unset(struct hci_dev *hdev, int type,
if (unlikely(handle < 0))
return NULL;
- return hci_conn_add(hdev, type, dst, role, handle);
+ conn = hci_conn_add(hdev, type, dst, role, handle);
+ if (!conn)
+ ida_free(&hdev->unset_handle_ida, handle);
+
+ return conn;
}
static void hci_conn_cleanup_child(struct hci_conn *conn, u8 reason)
@@ -2711,6 +2763,8 @@ struct hci_chan *hci_chan_create(struct hci_conn *conn)
skb_queue_head_init(&chan->data_q);
chan->state = BT_CONNECTED;
+ seqcount_init(&chan->tx_latency.seq);
+
list_add_rcu(&chan->list, &conn->chan_list);
return chan;
@@ -2928,3 +2982,57 @@ int hci_abort_conn(struct hci_conn *conn, u8 reason)
return hci_cmd_sync_queue_once(hdev, abort_conn_sync, conn, NULL);
}
+
+void hci_conn_tx_info_push(struct hci_conn *conn, void *ptr, __u16 sn)
+{
+ struct tx_info_queue *txq = &conn->tx_info_queue;
+ unsigned int tail;
+
+ if (!txq->num && !ptr)
+ return;
+ if (txq->num >= txq->size || !txq->info)
+ return;
+
+ tail = (txq->head + txq->num) % txq->size;
+ txq->info[tail].data = ptr;
+ txq->info[tail].sn = sn;
+ txq->num++;
+}
+
+void *hci_conn_tx_info_pop(struct hci_conn *conn, __u16 *sn)
+{
+ struct tx_info_queue *txq = &conn->tx_info_queue;
+ void *ptr;
+
+ if (!txq->num || !txq->info || !txq->size)
+ return NULL;
+
+ ptr = txq->info[txq->head].data;
+ *sn = txq->info[txq->head].sn;
+ txq->head = (txq->head + 1) % txq->size;
+ txq->num--;
+
+ return ptr;
+}
+
+void hci_mark_tx_latency(struct tx_latency *tx, struct sk_buff *skb)
+{
+ if (!skb)
+ return;
+
+ /* Reads may be concurrent */
+ WRITE_ONCE(tx->sn, tx->sn + 1u);
+
+ bt_cb(skb)->user_sn = tx->sn;
+ bt_cb(skb)->have_user_sn = true;
+}
+
+void hci_copy_tx_latency(struct tx_latency *dst, struct tx_latency *src)
+{
+ unsigned int seq;
+
+ do {
+ seq = read_seqcount_begin(&src->seq);
+ dst->now = src->now;
+ } while (read_seqcount_retry(&src->seq, seq));
+}
diff --git a/net/bluetooth/hci_core.c b/net/bluetooth/hci_core.c
index 6ca4c0df9f9c..bbdd8b28fb2c 100644
--- a/net/bluetooth/hci_core.c
+++ b/net/bluetooth/hci_core.c
@@ -3703,6 +3703,9 @@ static void hci_sched_acl_pkt(struct hci_dev *hdev)
(chan = hci_chan_sent(hdev, ACL_LINK, "e))) {
u32 priority = (skb_peek(&chan->data_q))->priority;
while (quote-- && (skb = skb_peek(&chan->data_q))) {
+ u16 sn = bt_cb(skb)->user_sn;
+ bool have_sn = bt_cb(skb)->have_user_sn;
+
BT_DBG("chan %p skb %p len %d priority %u", chan, skb,
skb->len, skb->priority);
@@ -3722,6 +3725,11 @@ static void hci_sched_acl_pkt(struct hci_dev *hdev)
chan->sent++;
chan->conn->sent++;
+ if (have_sn)
+ hci_conn_tx_info_push(chan->conn, chan, sn);
+ else
+ hci_conn_tx_info_push(chan->conn, NULL, 0);
+
/* Send pending SCO packets right away */
hci_sched_sco(hdev);
hci_sched_esco(hdev);
@@ -3875,9 +3883,15 @@ static void hci_sched_iso(struct hci_dev *hdev)
hdev->le_pkts ? &hdev->le_cnt : &hdev->acl_cnt;
while (*cnt && (conn = hci_low_sent(hdev, ISO_LINK, "e))) {
while (quote-- && (skb = skb_dequeue(&conn->data_q))) {
+ u16 sn = bt_cb(skb)->user_sn;
+ bool have_sn = bt_cb(skb)->have_user_sn;
+
BT_DBG("skb %p len %d", skb, skb->len);
+
hci_send_frame(hdev, skb);
+ hci_conn_tx_info_push(conn, UINT_PTR(have_sn), sn);
+
conn->sent++;
if (conn->sent == ~0)
conn->sent = 0;
diff --git a/net/bluetooth/hci_event.c b/net/bluetooth/hci_event.c
index bffd2c7ff608..144d4b481309 100644
--- a/net/bluetooth/hci_event.c
+++ b/net/bluetooth/hci_event.c
@@ -4417,10 +4417,72 @@ static void hci_role_change_evt(struct hci_dev *hdev, void *data,
hci_dev_unlock(hdev);
}
+static void update_acl_tx_latency(struct hci_conn *conn, int count, ktime_t now)
+{
+ unsigned int i;
+
+ rcu_read_lock();
+
+ for (i = 0; i < count; ++i) {
+ struct hci_chan *chan;
+ void *ptr;
+ u16 sn;
+
+ ptr = hci_conn_tx_info_pop(conn, &sn);
+ if (!ptr)
+ continue;
+
+ list_for_each_entry_rcu(chan, &conn->chan_list, list) {
+ struct tx_latency *tx = &chan->tx_latency;
+
+ if (chan != ptr)
+ continue;
+
+ preempt_disable();
+ write_seqcount_begin(&tx->seq);
+ tx->now.time = now;
+ tx->now.queue = (u16)(READ_ONCE(tx->sn) - sn);
+ tx->now.offset = 0;
+ write_seqcount_end(&tx->seq);
+ preempt_enable();
+ }
+ }
+
+ rcu_read_unlock();
+}
+
+static void update_iso_tx_latency(struct hci_conn *conn, int count, ktime_t now)
+{
+ struct tx_latency *tx = NULL;
+ u16 sn;
+ unsigned int i;
+
+ for (i = 0; i < count; ++i) {
+ u16 tx_sn;
+
+ if (hci_conn_tx_info_pop(conn, &tx_sn)) {
+ tx = &conn->tx_latency;
+ sn = tx_sn;
+ }
+ }
+
+ if (!tx)
+ return;
+
+ preempt_disable();
+ write_seqcount_begin(&tx->seq);
+ tx->now.time = now;
+ tx->now.queue = (u16)(READ_ONCE(tx->sn) - sn);
+ tx->now.offset = 0;
+ write_seqcount_end(&tx->seq);
+ preempt_enable();
+}
+
static void hci_num_comp_pkts_evt(struct hci_dev *hdev, void *data,
struct sk_buff *skb)
{
struct hci_ev_num_comp_pkts *ev = data;
+ ktime_t now = ktime_get();
int i;
if (!hci_ev_skb_pull(hdev, skb, HCI_EV_NUM_COMP_PKTS,
@@ -4450,6 +4512,8 @@ static void hci_num_comp_pkts_evt(struct hci_dev *hdev, void *data,
switch (conn->type) {
case ACL_LINK:
+ update_acl_tx_latency(conn, count, now);
+
hdev->acl_cnt += count;
if (hdev->acl_cnt > hdev->acl_pkts)
hdev->acl_cnt = hdev->acl_pkts;
@@ -4474,6 +4538,8 @@ static void hci_num_comp_pkts_evt(struct hci_dev *hdev, void *data,
break;
case ISO_LINK:
+ update_iso_tx_latency(conn, count, now);
+
if (hdev->iso_pkts) {
hdev->iso_cnt += count;
if (hdev->iso_cnt > hdev->iso_pkts)
--
2.44.0
^ permalink raw reply related [flat|nested] 8+ messages in thread
* [RFC PATCH 2/3] Bluetooth: ISO: add new ioctl() for reading tx latency
2024-02-28 20:03 [RFC PATCH 0/3] Bluetooth: add transmission latency tracking for ISO & L2CAP Pauli Virtanen
2024-02-28 20:03 ` [RFC PATCH 1/3] Bluetooth: add transmission latency tracking for ISO and ACL Pauli Virtanen
@ 2024-02-28 20:03 ` Pauli Virtanen
2024-02-28 20:03 ` [RFC PATCH 3/3] Bluetooth: L2CAP: " Pauli Virtanen
2024-02-28 20:31 ` [RFC PATCH 0/3] Bluetooth: add transmission latency tracking for ISO & L2CAP Luiz Augusto von Dentz
3 siblings, 0 replies; 8+ messages in thread
From: Pauli Virtanen @ 2024-02-28 20:03 UTC (permalink / raw
To: linux-bluetooth; +Cc: Pauli Virtanen
Add ioctl BTGETTXINFO to read information of a previous packet
completion event concerning a given ISO socket.
It contains sufficient information so the user can know which previous
sendmsg() the packet corresponds to and what was its completion time in
monotonic clock, so latency can be calculated. The user can then also
know the packet queue length (in units of their sendmsg packets).
Mark submitted skb so that hci_core updates the latency information, and
read it in the ioctl.
Signed-off-by: Pauli Virtanen <pav@iki.fi>
---
include/net/bluetooth/bluetooth.h | 37 ++++++++++++++++++++
net/bluetooth/iso.c | 58 ++++++++++++++++++++++++++++---
2 files changed, 90 insertions(+), 5 deletions(-)
diff --git a/include/net/bluetooth/bluetooth.h b/include/net/bluetooth/bluetooth.h
index f6bdd040adaa..ff4230d15461 100644
--- a/include/net/bluetooth/bluetooth.h
+++ b/include/net/bluetooth/bluetooth.h
@@ -239,6 +239,43 @@ struct bt_codecs {
#define BT_ISO_BASE 20
+/* BTGETTXINFO: Transmission latency information.
+ *
+ * Produces information of a previous event when a packet was sent, and the
+ * length of packet queue at that time.
+ *
+ * Applicable to: Bluetooth ISO sockets.
+ *
+ * Input: Zero-initialize reserved flag bits and other fields.
+ *
+ * Output:
+ *
+ * Fails with ENOENT if no packet has been sent.
+ *
+ * - flags: currently always 0, all bits reserved for extensions.
+ *
+ * - queue: total number of packets in queue (controller and socket buffers)
+ * at the time of the event.
+ *
+ * - time: reference event timestamp (nsec, in system monotonic clock).
+ *
+ * - offset: offset (nsec) of actual packet timing from the reference timestamp.
+ * Currently always 0.
+ *
+ * For packet latencies in nanoseconds, the application can track timestamps
+ * t[j] when it sent packet j. Then, given t[k] < tx_info.time < t[k + 1],
+ * event packet j = k - tx.queue and ref_latency_nsec = tx_info.time - t[j].
+ */
+
+#define BTGETTXINFO _IOWR('B', 100, struct bt_tx_info)
+
+struct bt_tx_info {
+ __u32 flags;
+ __u32 queue;
+ __s64 time;
+ __s64 offset;
+} __packed;
+
__printf(1, 2)
void bt_info(const char *fmt, ...);
__printf(1, 2)
diff --git a/net/bluetooth/iso.c b/net/bluetooth/iso.c
index 30c777c469f9..4953c987e4fd 100644
--- a/net/bluetooth/iso.c
+++ b/net/bluetooth/iso.c
@@ -500,6 +500,8 @@ static int iso_send_frame(struct sock *sk, struct sk_buff *skb)
if (skb->len > qos->ucast.out.sdu)
return -EMSGSIZE;
+ if (sk->sk_state != BT_CONNECTED)
+ return -ENOTCONN;
len = skb->len;
@@ -509,10 +511,9 @@ static int iso_send_frame(struct sock *sk, struct sk_buff *skb)
hdr->slen = cpu_to_le16(hci_iso_data_len_pack(len,
HCI_ISO_STATUS_VALID));
- if (sk->sk_state == BT_CONNECTED)
- hci_send_iso(conn->hcon, skb);
- else
- len = -ENOTCONN;
+ hci_mark_tx_latency(&conn->hcon->tx_latency, skb);
+
+ hci_send_iso(conn->hcon, skb);
return len;
}
@@ -2232,6 +2233,53 @@ void iso_recv(struct hci_conn *hcon, struct sk_buff *skb, u16 flags)
kfree_skb(skb);
}
+static int iso_sock_ioctl(struct socket *sock, unsigned int cmd,
+ unsigned long arg)
+{
+ struct sock *sk = sock->sk;
+ struct tx_latency latency;
+ struct bt_tx_info info;
+
+ BT_DBG("sk %p cmd %x arg %lx", sk, cmd, arg);
+
+ switch (cmd) {
+ case BTGETTXINFO:
+ /* Require zero-initialized, to allow later extensions */
+ if (copy_from_user(&info, (void __user *)arg, sizeof(info)))
+ return -EFAULT;
+ if (info.flags || info.queue || info.time || info.offset)
+ return -EINVAL;
+
+ memset(&info, 0, sizeof(info));
+
+ lock_sock(sk);
+
+ if (sk->sk_state != BT_CONNECTED) {
+ release_sock(sk);
+ return -EINVAL;
+ }
+
+ hci_copy_tx_latency(&latency,
+ &iso_pi(sk)->conn->hcon->tx_latency);
+
+ release_sock(sk);
+
+ if (!latency.now.time)
+ return -ENOENT;
+
+ info.queue = latency.now.queue;
+ info.time = ktime_to_ns(latency.now.time);
+ info.offset = latency.now.offset;
+
+ if (copy_to_user((void __user *)arg, &info, sizeof(info)))
+ return -EFAULT;
+
+ return 0;
+ }
+
+ return bt_sock_ioctl(sock, cmd, arg);
+}
+
static struct hci_cb iso_cb = {
.name = "ISO",
.connect_cfm = iso_connect_cfm,
@@ -2270,7 +2318,7 @@ static const struct proto_ops iso_sock_ops = {
.sendmsg = iso_sock_sendmsg,
.recvmsg = iso_sock_recvmsg,
.poll = bt_sock_poll,
- .ioctl = bt_sock_ioctl,
+ .ioctl = iso_sock_ioctl,
.mmap = sock_no_mmap,
.socketpair = sock_no_socketpair,
.shutdown = iso_sock_shutdown,
--
2.44.0
^ permalink raw reply related [flat|nested] 8+ messages in thread
* [RFC PATCH 3/3] Bluetooth: L2CAP: add new ioctl() for reading tx latency
2024-02-28 20:03 [RFC PATCH 0/3] Bluetooth: add transmission latency tracking for ISO & L2CAP Pauli Virtanen
2024-02-28 20:03 ` [RFC PATCH 1/3] Bluetooth: add transmission latency tracking for ISO and ACL Pauli Virtanen
2024-02-28 20:03 ` [RFC PATCH 2/3] Bluetooth: ISO: add new ioctl() for reading tx latency Pauli Virtanen
@ 2024-02-28 20:03 ` Pauli Virtanen
2024-02-28 20:31 ` [RFC PATCH 0/3] Bluetooth: add transmission latency tracking for ISO & L2CAP Luiz Augusto von Dentz
3 siblings, 0 replies; 8+ messages in thread
From: Pauli Virtanen @ 2024-02-28 20:03 UTC (permalink / raw
To: linux-bluetooth; +Cc: Pauli Virtanen
Add ioctl BTGETTXINFO to read information of a previous packet
completion event concerning a given L2CAP socket.
Mark skbs submitted so that hci_core updates latency info in the
hci_chan. Read the information in the ioctl.
The ioctl is the same as for ISO sockets.
Signed-off-by: Pauli Virtanen <pav@iki.fi>
---
include/net/bluetooth/bluetooth.h | 2 +-
net/bluetooth/l2cap_core.c | 12 ++++++++
net/bluetooth/l2cap_sock.c | 50 ++++++++++++++++++++++++++++++-
3 files changed, 62 insertions(+), 2 deletions(-)
diff --git a/include/net/bluetooth/bluetooth.h b/include/net/bluetooth/bluetooth.h
index ff4230d15461..480f5cbc24e4 100644
--- a/include/net/bluetooth/bluetooth.h
+++ b/include/net/bluetooth/bluetooth.h
@@ -244,7 +244,7 @@ struct bt_codecs {
* Produces information of a previous event when a packet was sent, and the
* length of packet queue at that time.
*
- * Applicable to: Bluetooth ISO sockets.
+ * Applicable to: Bluetooth ISO and L2CAP sockets.
*
* Input: Zero-initialize reserved flag bits and other fields.
*
diff --git a/net/bluetooth/l2cap_core.c b/net/bluetooth/l2cap_core.c
index 467b242d8be0..c70f935d9242 100644
--- a/net/bluetooth/l2cap_core.c
+++ b/net/bluetooth/l2cap_core.c
@@ -2488,6 +2488,13 @@ static void l2cap_le_flowctl_send(struct l2cap_chan *chan)
skb_queue_len(&chan->tx_q));
}
+static void mark_tx_latency(struct l2cap_chan *chan, struct sk_buff *skb)
+{
+ struct hci_chan *hchan = chan->conn->hchan;
+
+ hci_mark_tx_latency(&hchan->tx_latency, skb);
+}
+
int l2cap_chan_send(struct l2cap_chan *chan, struct msghdr *msg, size_t len)
{
struct sk_buff *skb;
@@ -2526,6 +2533,8 @@ int l2cap_chan_send(struct l2cap_chan *chan, struct msghdr *msg, size_t len)
if (err)
return err;
+ mark_tx_latency(chan, skb_peek(&seg_queue));
+
skb_queue_splice_tail_init(&seg_queue, &chan->tx_q);
l2cap_le_flowctl_send(chan);
@@ -2547,6 +2556,7 @@ int l2cap_chan_send(struct l2cap_chan *chan, struct msghdr *msg, size_t len)
if (IS_ERR(skb))
return PTR_ERR(skb);
+ mark_tx_latency(chan, skb);
l2cap_do_send(chan, skb);
err = len;
break;
@@ -2570,6 +2580,8 @@ int l2cap_chan_send(struct l2cap_chan *chan, struct msghdr *msg, size_t len)
if (err)
break;
+ mark_tx_latency(chan, skb_peek(&seg_queue));
+
if (chan->mode == L2CAP_MODE_ERTM)
l2cap_tx(chan, NULL, &seg_queue, L2CAP_EV_DATA_REQUEST);
else
diff --git a/net/bluetooth/l2cap_sock.c b/net/bluetooth/l2cap_sock.c
index 4287aa6cc988..08c130bd8b98 100644
--- a/net/bluetooth/l2cap_sock.c
+++ b/net/bluetooth/l2cap_sock.c
@@ -1207,6 +1207,54 @@ static int l2cap_sock_recvmsg(struct socket *sock, struct msghdr *msg,
return err;
}
+static int l2cap_sock_ioctl(struct socket *sock, unsigned int cmd,
+ unsigned long arg)
+{
+ struct sock *sk = sock->sk;
+ struct l2cap_chan *chan = l2cap_pi(sk)->chan;
+ struct tx_latency latency;
+ struct bt_tx_info info;
+
+ BT_DBG("sk %p cmd %x arg %lx", sk, cmd, arg);
+
+ switch (cmd) {
+ case BTGETTXINFO:
+ /* Require zero-initialized, to allow later extensions */
+ if (copy_from_user(&info, (void __user *)arg, sizeof(info)))
+ return -EFAULT;
+ if (info.flags || info.queue || info.time || info.offset)
+ return -EINVAL;
+
+ memset(&info, 0, sizeof(info));
+
+ lock_sock(sk);
+
+ if (sk->sk_state != BT_CONNECTED || !chan->conn ||
+ !chan->conn->hchan) {
+ release_sock(sk);
+ return -EINVAL;
+ }
+
+ hci_copy_tx_latency(&latency, &chan->conn->hchan->tx_latency);
+
+ release_sock(sk);
+
+ if (!latency.now.time)
+ return -ENOENT;
+
+ info.queue = latency.now.queue;
+ info.time = ktime_to_ns(latency.now.time);
+ info.offset = latency.now.offset;
+
+ if (copy_to_user((void __user *)arg, &info, sizeof(info)))
+ return -EFAULT;
+
+ return 0;
+ }
+
+ return bt_sock_ioctl(sock, cmd, arg);
+}
+
/* Kill socket (only if zapped and orphan)
* Must be called on unlocked socket, with l2cap channel lock.
*/
@@ -1883,7 +1931,7 @@ static const struct proto_ops l2cap_sock_ops = {
.sendmsg = l2cap_sock_sendmsg,
.recvmsg = l2cap_sock_recvmsg,
.poll = bt_sock_poll,
- .ioctl = bt_sock_ioctl,
+ .ioctl = l2cap_sock_ioctl,
.gettstamp = sock_gettstamp,
.mmap = sock_no_mmap,
.socketpair = sock_no_socketpair,
--
2.44.0
^ permalink raw reply related [flat|nested] 8+ messages in thread
* Re: [RFC PATCH 0/3] Bluetooth: add transmission latency tracking for ISO & L2CAP
2024-02-28 20:03 [RFC PATCH 0/3] Bluetooth: add transmission latency tracking for ISO & L2CAP Pauli Virtanen
` (2 preceding siblings ...)
2024-02-28 20:03 ` [RFC PATCH 3/3] Bluetooth: L2CAP: " Pauli Virtanen
@ 2024-02-28 20:31 ` Luiz Augusto von Dentz
2024-02-28 21:01 ` Luiz Augusto von Dentz
2024-02-28 22:15 ` Pauli Virtanen
3 siblings, 2 replies; 8+ messages in thread
From: Luiz Augusto von Dentz @ 2024-02-28 20:31 UTC (permalink / raw
To: Pauli Virtanen; +Cc: linux-bluetooth
Hi Pauli,
On Wed, Feb 28, 2024 at 3:11 PM Pauli Virtanen <pav@iki.fi> wrote:
>
> Add ISO/L2CAP socket ioctl() BTGETTXINFO which informs the user how long
> it took the kernel and controller to complete their sendmsg(), and how
> many sendmsg() are in socket and controller queues.
>
> This currently provides information of the latest packet only, in
> principle there could be a ringbuffer containing few latest packets, not
> clear if that would be useful.
>
> These patches allow fixing / working around controller(?) issue where
> two ISO streams in same group get desynchronized. Having accurate
> knowledge of the packet queue lengths, user application can drop packets
> if it detects the ISO streams are not in sync.
>
> Pipewire side:
> https://gitlab.freedesktop.org/pvir/pipewire/-/commits/iso-ts-test
>
> With this change, https://github.com/bluez/bluez/issues/515 is more or
> less fixed, and the sound server can figure out the total latency to
> audio rendering (tx latency + transport latency + presentation delay).
>
> For ISO, this can be changed to use LE Read ISO TX Sync, when the clock
> and sequence number synchronization issues there are figured out, and a
> quirk is added for controllers with nonfunctional implementation.
>
> For the L2CAP latency, I'll need to think a bit more what is the audio
> use case. Motivation was that AVDTP delay report values appear to be off
> by ~0..40 ms compared to observed audio latency and this amount can vary
> per connection and time, so not explained by unaccounted code
> algorithmic delays etc. Currently it's not clear if there is relation to
> TX side latency, so it may be down to receiver side implementation.
>
> This needs a bit more work to figure out, but the L2CAP patch is anyway
> here. Due to the possible fragmentation in ISO sendmsg(), it seems we
> anyway need the tx_info_queue thing and can't easily do it by counting
> packets, and L2CAP required part is small addition on top of that.
That is not how it is normally done with sockets, normally this is
done with use of SO_TIMESTAMPING which is then reported using the
socket error queue:
https://www.kernel.org/doc/html/latest/networking/timestamping.html
Sorry to tell you just now, you might have lost a lot of time doing
all of the changes, next time just drop and RFC early on with the
general design so you don't spend too much time before getting any
feedback.
> TBD: iso-tester / l2cap-tester tests
>
> Pauli Virtanen (3):
> Bluetooth: add transmission latency tracking for ISO and ACL
> Bluetooth: ISO: add new ioctl() for reading tx latency
> Bluetooth: L2CAP: add new ioctl() for reading tx latency
>
> include/net/bluetooth/bluetooth.h | 39 +++++++++++
> include/net/bluetooth/hci_core.h | 30 ++++++++
> net/bluetooth/hci_conn.c | 110 +++++++++++++++++++++++++++++-
> net/bluetooth/hci_core.c | 14 ++++
> net/bluetooth/hci_event.c | 66 ++++++++++++++++++
> net/bluetooth/iso.c | 58 ++++++++++++++--
> net/bluetooth/l2cap_core.c | 12 ++++
> net/bluetooth/l2cap_sock.c | 50 +++++++++++++-
> 8 files changed, 372 insertions(+), 7 deletions(-)
>
> --
> 2.44.0
>
>
--
Luiz Augusto von Dentz
^ permalink raw reply [flat|nested] 8+ messages in thread
* RE: Bluetooth: add transmission latency tracking for ISO & L2CAP
2024-02-28 20:03 ` [RFC PATCH 1/3] Bluetooth: add transmission latency tracking for ISO and ACL Pauli Virtanen
@ 2024-02-28 20:34 ` bluez.test.bot
0 siblings, 0 replies; 8+ messages in thread
From: bluez.test.bot @ 2024-02-28 20:34 UTC (permalink / raw
To: linux-bluetooth, pav
[-- Attachment #1: Type: text/plain, Size: 2358 bytes --]
This is automated email and please do not reply to this email!
Dear submitter,
Thank you for submitting the patches to the linux bluetooth mailing list.
This is a CI test results with your patch series:
PW Link:https://patchwork.kernel.org/project/bluetooth/list/?series=830847
---Test result---
Test Summary:
CheckPatch PASS 2.92 seconds
GitLint PASS 0.64 seconds
SubjectPrefix PASS 0.22 seconds
BuildKernel PASS 28.25 seconds
CheckAllWarning PASS 30.98 seconds
CheckSparse WARNING 36.36 seconds
CheckSmatch WARNING 98.52 seconds
BuildKernel32 PASS 26.86 seconds
TestRunnerSetup PASS 493.62 seconds
TestRunner_l2cap-tester PASS 17.87 seconds
TestRunner_iso-tester FAIL 32.55 seconds
TestRunner_bnep-tester PASS 4.78 seconds
TestRunner_mgmt-tester FAIL 112.87 seconds
TestRunner_rfcomm-tester PASS 7.27 seconds
TestRunner_sco-tester PASS 10.88 seconds
TestRunner_ioctl-tester PASS 7.79 seconds
TestRunner_mesh-tester PASS 5.82 seconds
TestRunner_smp-tester PASS 7.17 seconds
TestRunner_userchan-tester PASS 4.92 seconds
IncrementalBuild PASS 73.74 seconds
Details
##############################
Test: CheckSparse - WARNING
Desc: Run sparse tool with linux kernel
Output:
net/bluetooth/hci_event.c: note: in included file (through include/net/bluetooth/hci_core.h):
##############################
Test: CheckSmatch - WARNING
Desc: Run smatch tool with source
Output:
net/bluetooth/hci_event.c: note: in included file (through include/net/bluetooth/hci_core.h):
##############################
Test: TestRunner_iso-tester - FAIL
Desc: Run iso-tester with test-runner
Output:
Total: 117, Passed: 116 (99.1%), Failed: 1, Not Run: 0
Failed Test Cases
ISO Connect Suspend - Success Failed 6.215 seconds
##############################
Test: TestRunner_mgmt-tester - FAIL
Desc: Run mgmt-tester with test-runner
Output:
Total: 492, Passed: 489 (99.4%), Failed: 1, Not Run: 2
Failed Test Cases
LL Privacy - Start Discovery 2 (Disable RL) Failed 0.182 seconds
---
Regards,
Linux Bluetooth
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [RFC PATCH 0/3] Bluetooth: add transmission latency tracking for ISO & L2CAP
2024-02-28 20:31 ` [RFC PATCH 0/3] Bluetooth: add transmission latency tracking for ISO & L2CAP Luiz Augusto von Dentz
@ 2024-02-28 21:01 ` Luiz Augusto von Dentz
2024-02-28 22:15 ` Pauli Virtanen
1 sibling, 0 replies; 8+ messages in thread
From: Luiz Augusto von Dentz @ 2024-02-28 21:01 UTC (permalink / raw
To: Pauli Virtanen; +Cc: linux-bluetooth
Hi Pauli,
On Wed, Feb 28, 2024 at 3:31 PM Luiz Augusto von Dentz
<luiz.dentz@gmail.com> wrote:
>
> Hi Pauli,
>
> On Wed, Feb 28, 2024 at 3:11 PM Pauli Virtanen <pav@iki.fi> wrote:
> >
> > Add ISO/L2CAP socket ioctl() BTGETTXINFO which informs the user how long
> > it took the kernel and controller to complete their sendmsg(), and how
> > many sendmsg() are in socket and controller queues.
> >
> > This currently provides information of the latest packet only, in
> > principle there could be a ringbuffer containing few latest packets, not
> > clear if that would be useful.
> >
> > These patches allow fixing / working around controller(?) issue where
> > two ISO streams in same group get desynchronized. Having accurate
> > knowledge of the packet queue lengths, user application can drop packets
> > if it detects the ISO streams are not in sync.
> >
> > Pipewire side:
> > https://gitlab.freedesktop.org/pvir/pipewire/-/commits/iso-ts-test
> >
> > With this change, https://github.com/bluez/bluez/issues/515 is more or
> > less fixed, and the sound server can figure out the total latency to
> > audio rendering (tx latency + transport latency + presentation delay).
> >
> > For ISO, this can be changed to use LE Read ISO TX Sync, when the clock
> > and sequence number synchronization issues there are figured out, and a
> > quirk is added for controllers with nonfunctional implementation.
> >
> > For the L2CAP latency, I'll need to think a bit more what is the audio
> > use case. Motivation was that AVDTP delay report values appear to be off
> > by ~0..40 ms compared to observed audio latency and this amount can vary
> > per connection and time, so not explained by unaccounted code
> > algorithmic delays etc. Currently it's not clear if there is relation to
> > TX side latency, so it may be down to receiver side implementation.
> >
> > This needs a bit more work to figure out, but the L2CAP patch is anyway
> > here. Due to the possible fragmentation in ISO sendmsg(), it seems we
> > anyway need the tx_info_queue thing and can't easily do it by counting
> > packets, and L2CAP required part is small addition on top of that.
>
> That is not how it is normally done with sockets, normally this is
> done with use of SO_TIMESTAMPING which is then reported using the
> socket error queue:
>
> https://www.kernel.org/doc/html/latest/networking/timestamping.html
>
> Sorry to tell you just now, you might have lost a lot of time doing
> all of the changes, next time just drop and RFC early on with the
> general design so you don't spend too much time before getting any
> feedback.
There are some samples in the linux tree if you want to take a look:
https://kernel.googlesource.com/pub/scm/linux/kernel/git/torvalds/linux/+/refs/tags/v4.6/Documentation/networking/timestamping/txtimestamp.c
The nice thing with that is that it is not a new API and it has a
little bit more finer control since we can add support for the likes
of SCM_TSTAMP_SCHED, SCM_TSTAMP_SND and SCM_TSTAMP_ACK, so we have the
possible to instead the timing at different layers.
> > TBD: iso-tester / l2cap-tester tests
> >
> > Pauli Virtanen (3):
> > Bluetooth: add transmission latency tracking for ISO and ACL
> > Bluetooth: ISO: add new ioctl() for reading tx latency
> > Bluetooth: L2CAP: add new ioctl() for reading tx latency
> >
> > include/net/bluetooth/bluetooth.h | 39 +++++++++++
> > include/net/bluetooth/hci_core.h | 30 ++++++++
> > net/bluetooth/hci_conn.c | 110 +++++++++++++++++++++++++++++-
> > net/bluetooth/hci_core.c | 14 ++++
> > net/bluetooth/hci_event.c | 66 ++++++++++++++++++
> > net/bluetooth/iso.c | 58 ++++++++++++++--
> > net/bluetooth/l2cap_core.c | 12 ++++
> > net/bluetooth/l2cap_sock.c | 50 +++++++++++++-
> > 8 files changed, 372 insertions(+), 7 deletions(-)
> >
> > --
> > 2.44.0
> >
> >
>
>
> --
> Luiz Augusto von Dentz
--
Luiz Augusto von Dentz
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [RFC PATCH 0/3] Bluetooth: add transmission latency tracking for ISO & L2CAP
2024-02-28 20:31 ` [RFC PATCH 0/3] Bluetooth: add transmission latency tracking for ISO & L2CAP Luiz Augusto von Dentz
2024-02-28 21:01 ` Luiz Augusto von Dentz
@ 2024-02-28 22:15 ` Pauli Virtanen
1 sibling, 0 replies; 8+ messages in thread
From: Pauli Virtanen @ 2024-02-28 22:15 UTC (permalink / raw
To: Luiz Augusto von Dentz; +Cc: linux-bluetooth
Hi Luiz,
ke, 2024-02-28 kello 15:31 -0500, Luiz Augusto von Dentz kirjoitti:
> Hi Pauli,
>
> On Wed, Feb 28, 2024 at 3:11 PM Pauli Virtanen <pav@iki.fi> wrote:
> >
> > Add ISO/L2CAP socket ioctl() BTGETTXINFO which informs the user how long
> > it took the kernel and controller to complete their sendmsg(), and how
> > many sendmsg() are in socket and controller queues.
> >
> > This currently provides information of the latest packet only, in
> > principle there could be a ringbuffer containing few latest packets, not
> > clear if that would be useful.
> >
> > These patches allow fixing / working around controller(?) issue where
> > two ISO streams in same group get desynchronized. Having accurate
> > knowledge of the packet queue lengths, user application can drop packets
> > if it detects the ISO streams are not in sync.
> >
> > Pipewire side:
> > https://gitlab.freedesktop.org/pvir/pipewire/-/commits/iso-ts-test
> >
> > With this change, https://github.com/bluez/bluez/issues/515 is more or
> > less fixed, and the sound server can figure out the total latency to
> > audio rendering (tx latency + transport latency + presentation delay).
> >
> > For ISO, this can be changed to use LE Read ISO TX Sync, when the clock
> > and sequence number synchronization issues there are figured out, and a
> > quirk is added for controllers with nonfunctional implementation.
> >
> > For the L2CAP latency, I'll need to think a bit more what is the audio
> > use case. Motivation was that AVDTP delay report values appear to be off
> > by ~0..40 ms compared to observed audio latency and this amount can vary
> > per connection and time, so not explained by unaccounted code
> > algorithmic delays etc. Currently it's not clear if there is relation to
> > TX side latency, so it may be down to receiver side implementation.
> >
> > This needs a bit more work to figure out, but the L2CAP patch is anyway
> > here. Due to the possible fragmentation in ISO sendmsg(), it seems we
> > anyway need the tx_info_queue thing and can't easily do it by counting
> > packets, and L2CAP required part is small addition on top of that.
>
> That is not how it is normally done with sockets, normally this is
> done with use of SO_TIMESTAMPING which is then reported using the
> socket error queue:
>
> https://www.kernel.org/doc/html/latest/networking/timestamping.html
>
> Sorry to tell you just now, you might have lost a lot of time doing
> all of the changes, next time just drop and RFC early on with the
> general design so you don't spend too much time before getting any
> feedback.
Thanks, looks like I missed that was not just for RX timestamping.
We then need to hang on to the skbs to be timestamped in hci_core until
packet completion. Looks like skb_queue_* is used by drivers, so
probably skb_get and ringbuffer like in this patchset then.
> > TBD: iso-tester / l2cap-tester tests
> >
> > Pauli Virtanen (3):
> > Bluetooth: add transmission latency tracking for ISO and ACL
> > Bluetooth: ISO: add new ioctl() for reading tx latency
> > Bluetooth: L2CAP: add new ioctl() for reading tx latency
> >
> > include/net/bluetooth/bluetooth.h | 39 +++++++++++
> > include/net/bluetooth/hci_core.h | 30 ++++++++
> > net/bluetooth/hci_conn.c | 110 +++++++++++++++++++++++++++++-
> > net/bluetooth/hci_core.c | 14 ++++
> > net/bluetooth/hci_event.c | 66 ++++++++++++++++++
> > net/bluetooth/iso.c | 58 ++++++++++++++--
> > net/bluetooth/l2cap_core.c | 12 ++++
> > net/bluetooth/l2cap_sock.c | 50 +++++++++++++-
> > 8 files changed, 372 insertions(+), 7 deletions(-)
> >
> > --
> > 2.44.0
> >
> >
>
>
--
Pauli Virtanen
^ permalink raw reply [flat|nested] 8+ messages in thread
end of thread, other threads:[~2024-02-28 22:25 UTC | newest]
Thread overview: 8+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2024-02-28 20:03 [RFC PATCH 0/3] Bluetooth: add transmission latency tracking for ISO & L2CAP Pauli Virtanen
2024-02-28 20:03 ` [RFC PATCH 1/3] Bluetooth: add transmission latency tracking for ISO and ACL Pauli Virtanen
2024-02-28 20:34 ` Bluetooth: add transmission latency tracking for ISO & L2CAP bluez.test.bot
2024-02-28 20:03 ` [RFC PATCH 2/3] Bluetooth: ISO: add new ioctl() for reading tx latency Pauli Virtanen
2024-02-28 20:03 ` [RFC PATCH 3/3] Bluetooth: L2CAP: " Pauli Virtanen
2024-02-28 20:31 ` [RFC PATCH 0/3] Bluetooth: add transmission latency tracking for ISO & L2CAP Luiz Augusto von Dentz
2024-02-28 21:01 ` Luiz Augusto von Dentz
2024-02-28 22:15 ` Pauli Virtanen
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).