[BlueZ] monitor: Add TX frame number and speed estimation

Commit Message

Luiz Augusto von Dentz July 31, 2023, 8:08 p.m. UTC

From: Luiz Augusto von Dentz <[e-mail]>

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 |  4 +++-
 monitor/packet.c  | 37 ++++++++++++++++++++++++-------------
 monitor/packet.h  |  7 +++++++
 3 files changed, 34 insertions(+), 14 deletions(-)

Comments

[e-mail] July 31, 2023, 9:39 p.m. UTC | #1

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=771337

---Test result---

Test Summary:
CheckPatch                    PASS      0.64 seconds
GitLint                       PASS      0.39 seconds
BuildEll                      PASS      36.17 seconds
BluezMake                     PASS      1283.93 seconds
MakeCheck                     PASS      13.31 seconds
MakeDistcheck                 PASS      207.42 seconds
CheckValgrind                 PASS      333.37 seconds
CheckSmatch                   WARNING   471.14 seconds
bluezmakeextell               PASS      141.83 seconds
IncrementalBuild              PASS      1085.39 seconds
ScanBuild                     PASS      1513.19 seconds

Details
##############################
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

Patch

diff --git a/monitor/analyze.c b/monitor/analyze.c
index b4a7cf726ac9..ff3b419c4c38 100644
--- a/monitor/analyze.c
+++ b/monitor/analyze.c
@@ -221,11 +221,13 @@  static void conn_destroy(void *data)
 	print_field("%lu RX packets", conn->rx_num);
 	print_field("%lu TX packets", conn->tx_num);
 	print_field("%lu TX completed packets", conn->tx_num_comp);
-	print_field("%lld-%lld msec (~%lld msec) TX Latency",
+	print_field("%lld-%lld msec (~%lld msec/~lld Kb/s) TX Latency",
 			TV_MSEC(conn->tx_l.min), TV_MSEC(conn->tx_l.max),
 			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];