From: Luiz Augusto von Dentz <[email protected]>
This adds the frame information while decoding:
> HCI Event: Number of Completed Packets (0x13) plen 5
Num handles: 1
Handle: 256 Address: XX:XX:XX:XX:XX:XX
Count: 1
#188: len 850 (755 Kb/s)
Latency: 9 msec (3-21 msec ~6 msec)
Channel: 68 [PSM 25 mode Basic (0x00)] {chan 4}
Channel Latency: 9 msec (7-21 msec ~9 msec)
Or the speed estimation while analyzing:
Found BR-ACL connection with handle 256
Address: XX:XX:XX:XX:XX:XX
60 RX packets
22548 TX packets
22547 TX completed packets
3-73 msec (~11 msec) TX Latency
6-850 octets (~847 octets) TX packet size
~568 Kb/s TX transfer speed
---
monitor/analyze.c | 2 ++
monitor/packet.c | 37 ++++++++++++++++++++++++-------------
monitor/packet.h | 7 +++++++
3 files changed, 33 insertions(+), 13 deletions(-)
diff --git a/monitor/analyze.c b/monitor/analyze.c
index b4a7cf726ac9..db026190701d 100644
--- a/monitor/analyze.c
+++ b/monitor/analyze.c
@@ -226,6 +226,8 @@ static void conn_destroy(void *data)
TV_MSEC(conn->tx_l.med));
print_field("%u-%u octets (~%u octets) TX packet size",
conn->tx_pkt_min, conn->tx_pkt_max, conn->tx_pkt_med);
+ print_field("~%lld Kb/s TX transfer speed",
+ conn->tx_bytes * 8 / TV_MSEC(conn->tx_l.total));
plot_draw(conn->plot);
diff --git a/monitor/packet.c b/monitor/packet.c
index fb469cdeafed..84af03a0011f 100644
--- a/monitor/packet.c
+++ b/monitor/packet.c
@@ -10397,6 +10397,8 @@ static void role_change_evt(struct timeval *tv, uint16_t index,
void packet_latency_add(struct packet_latency *latency, struct timeval *delta)
{
+ timeradd(&latency->total, delta, &latency->total);
+
if ((!timerisset(&latency->min) || timercmp(delta, &latency->min, <))
&& delta->tv_sec >= 0 && delta->tv_usec >= 0)
latency->min = *delta;
@@ -10427,28 +10429,30 @@ void packet_latency_add(struct packet_latency *latency, struct timeval *delta)
static void packet_dequeue_tx(struct timeval *tv, uint16_t handle)
{
struct packet_conn_data *conn;
- struct timeval *tx;
+ struct packet_frame *frame;
struct timeval delta;
conn = packet_get_conn_data(handle);
if (!conn)
return;
- tx = queue_pop_head(conn->tx_q);
- if (!tx)
+ frame = queue_pop_head(conn->tx_q);
+ if (!frame)
return;
- timersub(tv, tx, &delta);
+ timersub(tv, &frame->tv, &delta);
packet_latency_add(&conn->tx_l, &delta);
+ print_field("#%zu: len %zu (%lld Kb/s)", frame->num, frame->len,
+ frame->len * 8 / TV_MSEC(delta));
print_field("Latency: %lld msec (%lld-%lld msec ~%lld msec)",
TV_MSEC(delta), TV_MSEC(conn->tx_l.min),
TV_MSEC(conn->tx_l.max), TV_MSEC(conn->tx_l.med));
l2cap_dequeue_frame(&delta, conn);
- free(tx);
+ free(frame);
}
static void num_completed_packets_evt(struct timeval *tv, uint16_t index,
@@ -12442,10 +12446,11 @@ void packet_hci_event(struct timeval *tv, struct ucred *cred, uint16_t index,
event_data->func(tv, index, data, hdr->plen);
}
-static void packet_queue_tx(struct timeval *tv, uint16_t handle)
+static void packet_enqueue_tx(struct timeval *tv, uint16_t handle,
+ size_t num, uint16_t len)
{
struct packet_conn_data *conn;
- struct timeval *tx;
+ struct packet_frame *frame;
conn = packet_get_conn_data(handle);
if (!conn)
@@ -12454,9 +12459,12 @@ static void packet_queue_tx(struct timeval *tv, uint16_t handle)
if (!conn->tx_q)
conn->tx_q = queue_new();
- tx = new0(struct timeval, 1);
- memcpy(tx, tv, sizeof(*tv));
- queue_push_tail(conn->tx_q, tx);
+ frame = new0(struct packet_frame, 1);
+ if (tv)
+ memcpy(&frame->tv, tv, sizeof(*tv));
+ frame->num = num;
+ frame->len = len;
+ queue_push_tail(conn->tx_q, frame);
}
void packet_hci_acldata(struct timeval *tv, struct ucred *cred, uint16_t index,
@@ -12497,7 +12505,8 @@ void packet_hci_acldata(struct timeval *tv, struct ucred *cred, uint16_t index,
handle_str, extra_str);
if (!in)
- packet_queue_tx(tv, acl_handle(handle));
+ packet_enqueue_tx(tv, acl_handle(handle),
+ index_list[index].frame, dlen);
if (size != dlen) {
print_text(COLOR_ERROR, "invalid packet size (%d != %d)",
@@ -12549,7 +12558,8 @@ void packet_hci_scodata(struct timeval *tv, struct ucred *cred, uint16_t index,
handle_str, extra_str);
if (!in)
- packet_queue_tx(tv, acl_handle(handle));
+ packet_enqueue_tx(tv, acl_handle(handle),
+ index_list[index].frame, hdr->dlen);
if (size != hdr->dlen) {
print_text(COLOR_ERROR, "invalid packet size (%d != %d)",
@@ -12599,7 +12609,8 @@ void packet_hci_isodata(struct timeval *tv, struct ucred *cred, uint16_t index,
handle_str, extra_str);
if (!in)
- packet_queue_tx(tv, acl_handle(handle));
+ packet_enqueue_tx(tv, acl_handle(handle),
+ index_list[index].frame, hdr->dlen);
if (size != hdr->dlen) {
print_text(COLOR_ERROR, "invalid packet size (%d != %d)",
diff --git a/monitor/packet.h b/monitor/packet.h
index 12cb68d508f8..750ce405e4bc 100644
--- a/monitor/packet.h
+++ b/monitor/packet.h
@@ -26,11 +26,18 @@
#define TV_MSEC(_tv) (long long)((_tv).tv_sec * 1000 + (_tv).tv_usec / 1000)
struct packet_latency {
+ struct timeval total;
struct timeval min;
struct timeval max;
struct timeval med;
};
+struct packet_frame {
+ struct timeval tv;
+ size_t num;
+ size_t len;
+};
+
struct packet_conn_data {
uint16_t index;
uint8_t src[6];
--
2.41.0
From: Luiz Augusto von Dentz <[email protected]>
This adds proper connection tracking to SCO/ISO connection by handling
the events that establishes them.
---
monitor/analyze.c | 108 +++++++++++++++++++++++++++++++++++++++++++++-
1 file changed, 107 insertions(+), 1 deletion(-)
diff --git a/monitor/analyze.c b/monitor/analyze.c
index 89b0382825dc..d0ad70d5dc74 100644
--- a/monitor/analyze.c
+++ b/monitor/analyze.c
@@ -253,7 +253,9 @@ static void conn_destroy(void *data)
TV_MSEC(conn->tx_l.med));
print_field("%u-%u octets (~%u octets) TX packet size",
conn->tx_pkt_min, conn->tx_pkt_max, conn->tx_pkt_med);
- print_field("~%lld Kb/s TX transfer speed",
+
+ if (TV_MSEC(conn->tx_l.total))
+ print_field("~%lld Kb/s TX transfer speed",
conn->tx_bytes * 8 / TV_MSEC(conn->tx_l.total));
plot_draw(conn->plot);
@@ -595,9 +597,110 @@ static void evt_num_completed_packets(struct hci_dev *dev, struct timeval *tv,
}
}
+static void evt_sync_conn_complete(struct hci_dev *dev, struct timeval *tv,
+ const void *data, uint16_t size)
+{
+ const struct bt_hci_evt_sync_conn_complete *evt = data;
+ struct hci_conn *conn;
+
+ if (evt->status)
+ return;
+
+ conn = conn_lookup_type(dev, le16_to_cpu(evt->handle), evt->link_type);
+ if (!conn)
+ return;
+
+ memcpy(conn->bdaddr, evt->bdaddr, 6);
+ conn->setup_seen = true;
+}
+
+static void evt_le_cis_established(struct hci_dev *dev, struct timeval *tv,
+ struct iovec *iov)
+{
+ const struct bt_hci_evt_le_cis_established *evt;
+ struct hci_conn *conn;
+
+ evt = util_iov_pull_mem(iov, sizeof(*evt));
+ if (!evt || evt->status)
+ return;
+
+ conn = conn_lookup_type(dev, le16_to_cpu(evt->conn_handle),
+ CONN_LE_ISO);
+ if (!conn)
+ return;
+
+ conn->setup_seen = true;
+}
+
+static void evt_le_big_complete(struct hci_dev *dev, struct timeval *tv,
+ struct iovec *iov)
+{
+ const struct bt_hci_evt_le_big_complete *evt;
+ int i;
+
+ evt = util_iov_pull_mem(iov, sizeof(*evt));
+ if (!evt || evt->status)
+ return;
+
+ for (i = 0; i < evt->num_bis; i++) {
+ struct hci_conn *conn;
+ uint16_t handle;
+
+ if (!util_iov_pull_le16(iov, &handle))
+ return;
+
+ conn = conn_lookup_type(dev, handle, CONN_LE_ISO);
+ if (conn)
+ conn->setup_seen = true;
+ }
+}
+
+static void evt_le_big_sync_established(struct hci_dev *dev, struct timeval *tv,
+ struct iovec *iov)
+{
+ const struct bt_hci_evt_le_big_sync_estabilished *evt;
+ int i;
+
+ evt = util_iov_pull_mem(iov, sizeof(*evt));
+ if (!evt || evt->status)
+ return;
+
+ for (i = 0; i < evt->num_bis; i++) {
+ struct hci_conn *conn;
+ uint16_t handle;
+
+ if (!util_iov_pull_le16(iov, &handle))
+ return;
+
+ conn = conn_lookup_type(dev, handle, CONN_LE_ISO);
+ if (conn)
+ conn->setup_seen = true;
+ }
+}
+
static void evt_le_meta_event(struct hci_dev *dev, struct timeval *tv,
const void *data, uint16_t size)
{
+ struct iovec iov = {
+ .iov_base = (void *)data,
+ .iov_len = size,
+ };
+ uint8_t subevt;
+
+ if (!util_iov_pull_u8(&iov, &subevt))
+ return;
+
+ switch (subevt) {
+ case BT_HCI_EVT_LE_CIS_ESTABLISHED:
+ evt_le_cis_established(dev, tv, &iov);
+ break;
+ case BT_HCI_EVT_LE_BIG_COMPLETE:
+ evt_le_big_complete(dev, tv, &iov);
+ break;
+ case BT_HCI_EVT_LE_BIG_SYNC_ESTABILISHED:
+ evt_le_big_sync_established(dev, tv, &iov);
+ break;
+ }
}
static void event_pkt(struct timeval *tv, uint16_t index,
@@ -629,6 +732,9 @@ static void event_pkt(struct timeval *tv, uint16_t index,
case BT_HCI_EVT_NUM_COMPLETED_PACKETS:
evt_num_completed_packets(dev, tv, data, size);
break;
+ case BT_HCI_EVT_SYNC_CONN_COMPLETE:
+ evt_sync_conn_complete(dev, tv, data, size);
+ break;
case BT_HCI_EVT_LE_META_EVENT:
evt_le_meta_event(dev, tv, data, size);
break;
--
2.41.0
From: Luiz Augusto von Dentz <[email protected]>
This prints channel latency information and use gnuplot when using
-a/--analyze to plot a graph of channels:
Found TX L2CAP channel with CID 68
PSM 25
22490 packets
7-50 msec (~11 msec) TX Latency
850-850 octets TX packet size
~569 Kb/s TX transfer speed
10000 +-+----------------------------------------------------------------+
+| ++ |
+| || + Packets +-----+ |
+| + || | |
1000 +-| | || |+ ++ |
+| | || || || + |
+| | || || ||+ +| |
+| | || || ||| || ++ ++ |
100 +-| | || || ||| || || || + |
+| | || || ||| || || || ++| + + |
+| | || || ||| || || || ||| | | |
+| | || || ||| || || || ||| |+ +| + |
| | || || ||| || || || ||| || || |+ + |
10 +-| | || || ||| || || || ||| || || || |+ |
+| | || || ||| || || || ||| || || || || + |
+| +| || || ||| || || || ||| || || || ||+ ++ |+ ++ + |
| || || || ||| || || || ||| || || || ||| || || || | |
1 +-| || || || ||| || || || ||| || || || ||| || || || | + + |
++----------------------------------------------------------------+
+ + + + + + + + + +
5 10 15 20 25 30 35 40 45 50
Latency (ms)
---
monitor/analyze.c | 169 +++++++++++++++++++++++++++++-----------------
1 file changed, 107 insertions(+), 62 deletions(-)
diff --git a/monitor/analyze.c b/monitor/analyze.c
index a016e26e31ac..89b0382825dc 100644
--- a/monitor/analyze.c
+++ b/monitor/analyze.c
@@ -78,6 +78,11 @@ struct hci_conn {
struct queue *chan_list;
};
+struct hci_conn_tx {
+ struct timeval tv;
+ struct l2cap_chan *chan;
+};
+
struct plot {
long long x_msec;
size_t y_count;
@@ -88,61 +93,15 @@ struct l2cap_chan {
uint16_t psm;
bool out;
unsigned long num;
+ size_t tx_bytes;
+ struct packet_latency tx_l;
+ struct queue *plot;
+ uint16_t tx_pkt_min;
+ uint16_t tx_pkt_max;
};
static struct queue *dev_list;
-static void chan_destroy(void *data)
-{
- struct l2cap_chan *chan = data;
-
- printf(" Found %s L2CAP channel with CID %u\n",
- chan->out ? "TX" : "RX", chan->cid);
- if (chan->psm)
- printf(" PSM %u\n", chan->psm);
- printf(" %lu packets\n", chan->num);
-
- free(chan);
-}
-
-static struct l2cap_chan *chan_alloc(struct hci_conn *conn, uint16_t cid,
- bool out)
-{
- struct l2cap_chan *chan;
-
- chan = new0(struct l2cap_chan, 1);
-
- chan->cid = cid;
- chan->out = out;
-
- return chan;
-}
-
-static bool chan_match_cid(const void *a, const void *b)
-{
- const struct l2cap_chan *chan = a;
- uint32_t val = PTR_TO_UINT(b);
- uint16_t cid = val & 0xffff;
- bool out = val & 0x10000;
-
- return chan->cid == cid && chan->out == out;
-}
-
-static struct l2cap_chan *chan_lookup(struct hci_conn *conn, uint16_t cid,
- bool out)
-{
- struct l2cap_chan *chan;
- uint32_t val = cid | (out ? 0x10000 : 0);
-
- chan = queue_find(conn->chan_list, chan_match_cid, UINT_TO_PTR(val));
- if (!chan) {
- chan = chan_alloc(conn, cid, out);
- queue_push_tail(conn->chan_list, chan);
- }
-
- return chan;
-}
-
static void tmp_write(void *data, void *user_data)
{
struct plot *plot = data;
@@ -184,6 +143,74 @@ done:
unlink(filename);
}
+static void chan_destroy(void *data)
+{
+ struct l2cap_chan *chan = data;
+
+ printf(" Found %s L2CAP channel with CID %u\n",
+ chan->out ? "TX" : "RX", chan->cid);
+ if (chan->psm)
+ print_field("PSM %u", chan->psm);
+
+ print_field("%lu packets", chan->num);
+
+ if (!queue_isempty(chan->plot)) {
+ print_field("%lld-%lld msec (~%lld msec) TX Latency",
+ TV_MSEC(chan->tx_l.min), TV_MSEC(chan->tx_l.max),
+ TV_MSEC(chan->tx_l.med));
+ print_field("%u-%u octets TX packet size",
+ chan->tx_pkt_min, chan->tx_pkt_max);
+ }
+
+ if (TV_MSEC(chan->tx_l.total))
+ print_field("~%lld Kb/s TX transfer speed",
+ chan->tx_bytes * 8 / TV_MSEC(chan->tx_l.total));
+
+ if (chan->num > 1)
+ plot_draw(chan->plot);
+
+ free(chan);
+}
+
+static struct l2cap_chan *chan_alloc(struct hci_conn *conn, uint16_t cid,
+ bool out)
+{
+ struct l2cap_chan *chan;
+
+ chan = new0(struct l2cap_chan, 1);
+
+ chan->cid = cid;
+ chan->out = out;
+ chan->plot = queue_new();
+
+ return chan;
+}
+
+static bool chan_match_cid(const void *a, const void *b)
+{
+ const struct l2cap_chan *chan = a;
+ uint32_t val = PTR_TO_UINT(b);
+ uint16_t cid = val & 0xffff;
+ bool out = val & 0x10000;
+
+ return chan->cid == cid && chan->out == out;
+}
+
+static struct l2cap_chan *chan_lookup(struct hci_conn *conn, uint16_t cid,
+ bool out)
+{
+ struct l2cap_chan *chan;
+ uint32_t val = cid | (out ? 0x10000 : 0);
+
+ chan = queue_find(conn->chan_list, chan_match_cid, UINT_TO_PTR(val));
+ if (!chan) {
+ chan = chan_alloc(conn, cid, out);
+ queue_push_tail(conn->chan_list, chan);
+ }
+
+ return chan;
+}
+
static void conn_destroy(void *data)
{
struct hci_conn *conn = data;
@@ -506,9 +533,11 @@ static void plot_add(struct queue *queue, struct timeval *latency,
{
struct plot *plot;
- plot = queue_find(queue, match_plot_latency, latency);
+ /* Use LRU ordering */
+ plot = queue_remove_if(queue, match_plot_latency, latency);
if (plot) {
plot->y_count += count;
+ queue_push_head(queue, plot);
return;
}
@@ -533,7 +562,7 @@ static void evt_num_completed_packets(struct hci_dev *dev, struct timeval *tv,
uint16_t count = get_le16(data + 2);
struct hci_conn *conn;
struct timeval res;
- struct timeval *last_tx;
+ struct hci_conn_tx *last_tx;
int j;
data += 4;
@@ -548,11 +577,17 @@ static void evt_num_completed_packets(struct hci_dev *dev, struct timeval *tv,
for (j = 0; j < count; j++) {
last_tx = queue_pop_head(conn->tx_queue);
if (last_tx) {
- timersub(tv, last_tx, &res);
+ struct l2cap_chan *chan = last_tx->chan;
+
+ timersub(tv, &last_tx->tv, &res);
packet_latency_add(&conn->tx_l, &res);
+ plot_add(conn->plot, &res, 1);
- plot_add(conn->plot, &res, count);
+ if (chan) {
+ packet_latency_add(&chan->tx_l, &res);
+ plot_add(chan->plot, &res, 1);
+ }
free(last_tx);
}
@@ -601,14 +636,15 @@ static void event_pkt(struct timeval *tv, uint16_t index,
}
static void conn_pkt_tx(struct hci_conn *conn, struct timeval *tv,
- uint16_t size)
+ uint16_t size, struct l2cap_chan *chan)
{
- struct timeval *last_tx;
+ struct hci_conn_tx *last_tx;
conn->tx_num++;
- last_tx = new0(struct timeval, 1);
+ last_tx = new0(struct hci_conn_tx, 1);
memcpy(last_tx, tv, sizeof(*tv));
+ last_tx->chan = chan;
queue_push_tail(conn->tx_queue, last_tx);
conn->tx_bytes += size;
@@ -616,6 +652,15 @@ static void conn_pkt_tx(struct hci_conn *conn, struct timeval *tv,
conn->tx_pkt_min = size;
if (!conn->tx_pkt_max || size > conn->tx_pkt_max)
conn->tx_pkt_max = size;
+
+ if (chan) {
+ chan->tx_bytes += size;
+
+ if (!chan->tx_pkt_min || size < chan->tx_pkt_min)
+ chan->tx_pkt_min = size;
+ if (!chan->tx_pkt_max || size > chan->tx_pkt_max)
+ chan->tx_pkt_max = size;
+ }
}
static void acl_pkt(struct timeval *tv, uint16_t index, bool out,
@@ -624,7 +669,7 @@ static void acl_pkt(struct timeval *tv, uint16_t index, bool out,
const struct bt_hci_acl_hdr *hdr = data;
struct hci_dev *dev;
struct hci_conn *conn;
- struct l2cap_chan *chan;
+ struct l2cap_chan *chan = NULL;
uint16_t cid;
data += sizeof(*hdr);
@@ -655,7 +700,7 @@ static void acl_pkt(struct timeval *tv, uint16_t index, bool out,
}
if (out) {
- conn_pkt_tx(conn, tv, size);
+ conn_pkt_tx(conn, tv, size, chan);
} else {
conn->rx_num++;
}
@@ -681,7 +726,7 @@ static void sco_pkt(struct timeval *tv, uint16_t index, bool out,
return;
if (out) {
- conn_pkt_tx(conn, tv, size - sizeof(*hdr));
+ conn_pkt_tx(conn, tv, size - sizeof(*hdr), NULL);
} else {
conn->rx_num++;
}
@@ -768,7 +813,7 @@ static void iso_pkt(struct timeval *tv, uint16_t index, bool out,
return;
if (out) {
- conn_pkt_tx(conn, tv, size - sizeof(*hdr));
+ conn_pkt_tx(conn, tv, size - sizeof(*hdr), NULL);
} else {
conn->rx_num++;
}
--
2.41.0
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=771865
---Test result---
Test Summary:
CheckPatch FAIL 2.92 seconds
GitLint PASS 1.69 seconds
BuildEll PASS 26.88 seconds
BluezMake PASS 793.19 seconds
MakeCheck PASS 11.78 seconds
MakeDistcheck PASS 156.15 seconds
CheckValgrind PASS 251.54 seconds
CheckSmatch WARNING 339.63 seconds
bluezmakeextell PASS 102.48 seconds
IncrementalBuild PASS 3298.44 seconds
ScanBuild PASS 1023.86 seconds
Details
##############################
Test: CheckPatch - FAIL
Desc: Run checkpatch.pl script
Output:
[BlueZ,v2,3/5] monitor: Print channel latency information with -a/--analyze
WARNING:COMMIT_LOG_LONG_LINE: Possible unwrapped commit description (prefer a maximum 75 chars per line)
#96:
10000 +-+----------------------------------------------------------------+
/github/workspace/src/src/13337349.patch total: 0 errors, 1 warnings, 255 lines checked
NOTE: For some of the reported defects, checkpatch may be able to
mechanically convert to the typical style using --fix or --fix-inplace.
/github/workspace/src/src/13337349.patch has style problems, please review.
NOTE: Ignored message types: COMMIT_MESSAGE COMPLEX_MACRO CONST_STRUCT FILE_PATH_CHANGES MISSING_SIGN_OFF PREFER_PACKED SPDX_LICENSE_TAG SPLIT_STRING SSCANF_TO_KSTRTO
NOTE: If any of the errors are false positives, please report
them to the maintainer, see CHECKPATCH in MAINTAINERS.
##############################
Test: CheckSmatch - WARNING
Desc: Run smatch tool with source
Output:
monitor/packet.c: note: in included file:monitor/display.h:82:26: warning: Variable length array is used.monitor/packet.c:1832:26: warning: Variable length array is used.monitor/packet.c: note: in included file:monitor/bt.h:3602:52: warning: array of flexible structuresmonitor/bt.h:3590:40: warning: array of flexible structures
---
Regards,
Linux Bluetooth