linux-bluetooth.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [BlueZ PATCH v5 1/7] monitor: Use gnuplot to plot graph of Latency-Packets
@ 2023-07-28 22:42 Luiz Augusto von Dentz
  2023-07-28 22:42 ` [BlueZ PATCH v5 2/7] monitor: Update documentation Luiz Augusto von Dentz
                   ` (7 more replies)
  0 siblings, 8 replies; 9+ messages in thread
From: Luiz Augusto von Dentz @ 2023-07-28 22:42 UTC (permalink / raw)
  To: linux-bluetooth

From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>

This make use of gnuplot when using -a/--analyze to plot a graph of
Latency-Packets:

  Found BR-ACL connection with handle 256
        Address: XX:XX:XX:XX:XX:XX (Sony Home Entertainment&Sound Products Inc)
        60 RX packets
        22548 TX packets
        22547 TX completed packets
        3 msec min latency
        73 msec max latency
        11 msec median latency
        6 octets TX min packet size
        850 octets TX max packet size
        847 octets TX median packet size

  10000 +-+----------------------------------------------------------------+
         +|      ++                                                        |
         +|      ||+                                       Packets +-----+ |
         +|      |||                                                       |
   1000 +-|      |||++                                                     |
         +|      |||||  +                                                  |
         +|      |||||++|                                                  |
         +|      ||||||||+++                                               |
    100 +-|      |||||||||||  +                                            |
         +|      |||||||||||+++  +                                         |
         +|      ||||||||||||||  |                                         |
         +| ++   ||||||||||||||++|+                                        |
          | ||   |||||||||||||||||++                                       |
     10 +-| ||   |||||||||||||||||||+                                      |
         +| ||   ||||||||||||||||||||  +                                   |
         +| || ++||||||||||||||||||||++|++++       +                       |
          | || |||||||||||||||||||||||||||||       |                       |
      1 +-| ||+||||||||||||||||||||||||||||| +  +  |                 +     |
         ++----------------------------------------------------------------+
          +       +       +       +        +       +       +       +       +
          0       10      20      30       40      50      60      70      80
                                    Latency (ms)
---
 monitor/analyze.c | 98 +++++++++++++++++++++++++++++++++++++++++------
 1 file changed, 87 insertions(+), 11 deletions(-)

diff --git a/monitor/analyze.c b/monitor/analyze.c
index a20ba98b0be4..991373dbb348 100644
--- a/monitor/analyze.c
+++ b/monitor/analyze.c
@@ -17,6 +17,7 @@
 #include <stdio.h>
 #include <string.h>
 #include <sys/time.h>
+#include <unistd.h>
 
 #include "lib/bluetooth.h"
 
@@ -28,6 +29,9 @@
 #include "monitor/packet.h"
 #include "monitor/analyze.h"
 
+#define TIMEVAL_MSEC(_tv) \
+	(long long)((_tv)->tv_sec * 1000 + (_tv)->tv_usec / 1000)
+
 struct hci_dev {
 	uint16_t index;
 	uint8_t type;
@@ -69,12 +73,18 @@ struct hci_conn {
 	struct timeval tx_lat_min;
 	struct timeval tx_lat_max;
 	struct timeval tx_lat_med;
+	struct queue *plot;
 	uint16_t tx_pkt_min;
 	uint16_t tx_pkt_max;
 	uint16_t tx_pkt_med;
 	struct queue *chan_list;
 };
 
+struct plot {
+	long long x_msec;
+	size_t y_count;
+};
+
 struct l2cap_chan {
 	uint16_t cid;
 	uint16_t psm;
@@ -135,6 +145,47 @@ static struct l2cap_chan *chan_lookup(struct hci_conn *conn, uint16_t cid,
 	return chan;
 }
 
+static void tmp_write(void *data, void *user_data)
+{
+	struct plot *plot = data;
+	FILE *tmp = user_data;
+
+	fprintf(tmp, "%lld %zu\n", plot->x_msec, plot->y_count);
+}
+
+static void plot_draw(struct queue *queue)
+{
+	const char *filename = "analyze.tmp";
+	FILE *gplot = popen("gnuplot", "w");
+	FILE *tmp;
+
+	if (!gplot)
+		return;
+
+	if (queue_isempty(queue))
+		goto done;
+
+	tmp = fopen(filename, "w");
+	if (!tmp)
+		goto done;
+
+	queue_foreach(queue, tmp_write, tmp);
+
+	fprintf(gplot, "set terminal dumb enhanced ansi\n");
+	fprintf(gplot, "set xlabel 'Latency (ms)'\n");
+	fprintf(gplot, "set tics out nomirror\n");
+	fprintf(gplot, "set log y\n");
+	fprintf(gplot, "set yrange [0.5:*]\n");
+	fprintf(gplot, "plot './%s' using 1:2 t 'Packets' w impulses\n",
+								filename);
+	fflush(gplot);
+
+	fclose(tmp);
+done:
+	pclose(gplot);
+	unlink(filename);
+}
+
 static void conn_destroy(void *data)
 {
 	struct hci_conn *conn = data;
@@ -172,21 +223,17 @@ 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 msec min latency",
-			(long long)
-			(conn->tx_lat_min.tv_sec * 1000 +
-			conn->tx_lat_min.tv_usec / 1000));
-	print_field("%lld msec max latency",
-			(long long)
-			(conn->tx_lat_max.tv_sec * 1000 +
-			conn->tx_lat_max.tv_usec / 1000));
+	print_field("%lld msec min latency", TIMEVAL_MSEC(&conn->tx_lat_min));
+	print_field("%lld msec max latency", TIMEVAL_MSEC(&conn->tx_lat_max));
 	print_field("%lld msec median latency",
-			(long long)
-			(conn->tx_lat_med.tv_sec * 1000 +
-			conn->tx_lat_med.tv_usec / 1000));
+			TIMEVAL_MSEC(&conn->tx_lat_med));
 	print_field("%u octets TX min packet size", conn->tx_pkt_min);
 	print_field("%u octets TX max packet size", conn->tx_pkt_max);
 	print_field("%u octets TX median packet size", conn->tx_pkt_med);
+
+	plot_draw(conn->plot);
+
+	queue_destroy(conn->plot, free);
 	queue_destroy(conn->chan_list, chan_destroy);
 
 	queue_destroy(conn->tx_queue, free);
@@ -203,6 +250,7 @@ static struct hci_conn *conn_alloc(struct hci_dev *dev, uint16_t handle,
 	conn->handle = handle;
 	conn->type = type;
 	conn->tx_queue = queue_new();
+	conn->plot = queue_new();
 
 	conn->chan_list = queue_new();
 
@@ -447,6 +495,32 @@ static void evt_cmd_complete(struct hci_dev *dev, struct timeval *tv,
 	}
 }
 
+static bool match_plot_latency(const void *data, const void *user_data)
+{
+	const struct plot *plot = data;
+	const struct timeval *latency = user_data;
+
+	return TIMEVAL_MSEC(latency) == plot->x_msec;
+}
+
+static void plot_add(struct queue *queue, struct timeval *latency,
+						uint16_t count)
+{
+	struct plot *plot;
+
+	plot = queue_find(queue, match_plot_latency, latency);
+	if (plot) {
+		plot->y_count += count;
+		return;
+	}
+
+	plot = new0(struct plot, 1);
+	plot->x_msec = TIMEVAL_MSEC(latency);
+	plot->y_count = count;
+
+	queue_push_tail(queue, plot);
+}
+
 static void evt_num_completed_packets(struct hci_dev *dev, struct timeval *tv,
 					const void *data, uint16_t size)
 {
@@ -504,6 +578,8 @@ static void evt_num_completed_packets(struct hci_dev *dev, struct timeval *tv,
 			} else
 				conn->tx_lat_med = res;
 
+			plot_add(conn->plot, &res, count);
+
 			free(last_tx);
 		}
 	}
-- 
2.41.0


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

* [BlueZ PATCH v5 2/7] monitor: Update documentation
  2023-07-28 22:42 [BlueZ PATCH v5 1/7] monitor: Use gnuplot to plot graph of Latency-Packets Luiz Augusto von Dentz
@ 2023-07-28 22:42 ` Luiz Augusto von Dentz
  2023-07-28 22:42 ` [BlueZ PATCH v5 3/7] monitor: Consolidate code around latency calculation Luiz Augusto von Dentz
                   ` (6 subsequent siblings)
  7 siblings, 0 replies; 9+ messages in thread
From: Luiz Augusto von Dentz @ 2023-07-28 22:42 UTC (permalink / raw)
  To: linux-bluetooth

From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>

This updates the documentation to mention gnuplot usage.
---
 monitor/btmon.rst | 4 +++-
 monitor/main.c    | 3 +++
 2 files changed, 6 insertions(+), 1 deletion(-)

diff --git a/monitor/btmon.rst b/monitor/btmon.rst
index 0ab13eb2eb5c..82f9381c151d 100644
--- a/monitor/btmon.rst
+++ b/monitor/btmon.rst
@@ -33,7 +33,9 @@ OPTIONS
 -w FILE, --write FILE       Save traces in btsnoop format to *FILE*.
 -a FILE, --analyze FILE     Analyze traces in btsnoop format from *FILE*.
                             It displays the devices found in the *FILE* with
-                            its packets by type.
+			    its packets by type. If gnuplot is installed on
+			    the system it also attempts to plot packet latency
+			    graph.
 -s SOCKET, --server SOCKET  Start monitor server socket.
 -p PRIORITY, --priority PRIORITY  Show only priority or lower for user log.
 
diff --git a/monitor/main.c b/monitor/main.c
index decf7cc467f2..fa56fcb29f38 100644
--- a/monitor/main.c
+++ b/monitor/main.c
@@ -51,6 +51,9 @@ static void usage(void)
 		"\t-r, --read <file>      Read traces in btsnoop format\n"
 		"\t-w, --write <file>     Save traces in btsnoop format\n"
 		"\t-a, --analyze <file>   Analyze traces in btsnoop format\n"
+		"\t                       If gnuplot is installed on the\n"
+                "\t                       system it will also attempt to plot\n"
+		"\t                       packet latency graph.\n"
 		"\t-s, --server <socket>  Start monitor server socket\n"
 		"\t-p, --priority <level> Show only priority or lower\n"
 		"\t-i, --index <num>      Show only specified controller\n"
-- 
2.41.0


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

* [BlueZ PATCH v5 3/7] monitor: Consolidate code around latency calculation
  2023-07-28 22:42 [BlueZ PATCH v5 1/7] monitor: Use gnuplot to plot graph of Latency-Packets Luiz Augusto von Dentz
  2023-07-28 22:42 ` [BlueZ PATCH v5 2/7] monitor: Update documentation Luiz Augusto von Dentz
@ 2023-07-28 22:42 ` Luiz Augusto von Dentz
  2023-07-28 22:42 ` [BlueZ PATCH v5 4/7] monitor: Fix not dequeing TX packet properly Luiz Augusto von Dentz
                   ` (5 subsequent siblings)
  7 siblings, 0 replies; 9+ messages in thread
From: Luiz Augusto von Dentz @ 2023-07-28 22:42 UTC (permalink / raw)
  To: linux-bluetooth

From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>

This move latency calculations to a helper function called
packet_latency_add so it can get reused by the likes of l2cap.c and
analyze.c
---
 monitor/analyze.c | 44 ++++++-----------------------------
 monitor/l2cap.c   | 36 ++++-------------------------
 monitor/packet.c  | 59 +++++++++++++++++++++++++----------------------
 monitor/packet.h  | 12 +++++++---
 4 files changed, 51 insertions(+), 100 deletions(-)

diff --git a/monitor/analyze.c b/monitor/analyze.c
index 991373dbb348..ddaaf6942035 100644
--- a/monitor/analyze.c
+++ b/monitor/analyze.c
@@ -70,9 +70,7 @@ struct hci_conn {
 	unsigned long tx_num_comp;
 	size_t tx_bytes;
 	struct queue *tx_queue;
-	struct timeval tx_lat_min;
-	struct timeval tx_lat_max;
-	struct timeval tx_lat_med;
+	struct packet_latency tx_l;
 	struct queue *plot;
 	uint16_t tx_pkt_min;
 	uint16_t tx_pkt_max;
@@ -223,13 +221,11 @@ 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 msec min latency", TIMEVAL_MSEC(&conn->tx_lat_min));
-	print_field("%lld msec max latency", TIMEVAL_MSEC(&conn->tx_lat_max));
-	print_field("%lld msec median latency",
-			TIMEVAL_MSEC(&conn->tx_lat_med));
-	print_field("%u octets TX min packet size", conn->tx_pkt_min);
-	print_field("%u octets TX max packet size", conn->tx_pkt_max);
-	print_field("%u octets TX median packet size", conn->tx_pkt_med);
+	print_field("%lld-%lld msec (~%lld msec) 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);
 
 	plot_draw(conn->plot);
 
@@ -550,33 +546,7 @@ static void evt_num_completed_packets(struct hci_dev *dev, struct timeval *tv,
 		if (last_tx) {
 			timersub(tv, last_tx, &res);
 
-			if ((!timerisset(&conn->tx_lat_min) ||
-					timercmp(&res, &conn->tx_lat_min, <)) &&
-					res.tv_sec >= 0 && res.tv_usec >= 0)
-				conn->tx_lat_min = res;
-
-			if (!timerisset(&conn->tx_lat_max) ||
-					timercmp(&res, &conn->tx_lat_max, >))
-				conn->tx_lat_max = res;
-
-			if (timerisset(&conn->tx_lat_med)) {
-				struct timeval tmp;
-
-				timeradd(&conn->tx_lat_med, &res, &tmp);
-
-				tmp.tv_sec /= 2;
-				tmp.tv_usec /= 2;
-				if (tmp.tv_sec % 2) {
-					tmp.tv_usec += 500000;
-					if (tmp.tv_usec >= 1000000) {
-						tmp.tv_sec++;
-						tmp.tv_usec -= 1000000;
-					}
-				}
-
-				conn->tx_lat_med = tmp;
-			} else
-				conn->tx_lat_med = res;
+			packet_latency_add(&conn->tx_l, &res);
 
 			plot_add(conn->plot, &res, count);
 
diff --git a/monitor/l2cap.c b/monitor/l2cap.c
index 8258475d26dc..8f3d8e65b510 100644
--- a/monitor/l2cap.c
+++ b/monitor/l2cap.c
@@ -100,9 +100,7 @@ struct chan_data {
 	uint8_t  ext_ctrl;
 	uint8_t  seq_num;
 	uint16_t sdu;
-	struct timeval tx_min;
-	struct timeval tx_max;
-	struct timeval tx_med;
+	struct packet_latency tx_l;
 };
 
 static struct chan_data chan_list[MAX_CHAN];
@@ -2798,8 +2796,6 @@ void l2cap_packet(uint16_t index, bool in, uint16_t handle, uint8_t flags,
 	}
 }
 
-#define TV_MSEC(_tv) (long long)((_tv)->tv_sec * 1000 + (_tv)->tv_usec / 1000)
-
 void l2cap_dequeue_frame(struct timeval *delta, struct packet_conn_data *conn)
 {
 	struct l2cap_frame *frame;
@@ -2813,39 +2809,15 @@ void l2cap_dequeue_frame(struct timeval *delta, struct packet_conn_data *conn)
 	if (!chan)
 		return;
 
-	if ((!timerisset(&chan->tx_min) || timercmp(delta, &chan->tx_min, <))
-				&& delta->tv_sec >= 0 && delta->tv_usec >= 0)
-		chan->tx_min = *delta;
-
-	if (!timerisset(&chan->tx_max) || timercmp(delta, &chan->tx_max, >))
-		chan->tx_max = *delta;
-
-	if (timerisset(&chan->tx_med)) {
-		struct timeval tmp;
-
-		timeradd(&chan->tx_med, delta, &tmp);
-
-		tmp.tv_sec /= 2;
-		tmp.tv_usec /= 2;
-		if (tmp.tv_sec % 2) {
-			tmp.tv_usec += 500000;
-			if (tmp.tv_usec >= 1000000) {
-				tmp.tv_sec++;
-				tmp.tv_usec -= 1000000;
-			}
-		}
-
-		chan->tx_med = tmp;
-	} else
-		chan->tx_med = *delta;
+	packet_latency_add(&chan->tx_l, delta);
 
 	print_field("Channel: %d [PSM %d mode %s (0x%02x)] {chan %d}",
 			frame->cid, frame->psm, mode2str(frame->mode),
 			frame->mode, frame->chan);
 
 	print_field("Channel Latency: %lld msec (%lld-%lld msec ~%lld msec)",
-			TV_MSEC(delta), TV_MSEC(&chan->tx_min),
-			TV_MSEC(&chan->tx_max), TV_MSEC(&chan->tx_med));
+			TV_MSEC(*delta), TV_MSEC(chan->tx_l.min),
+			TV_MSEC(chan->tx_l.max), TV_MSEC(chan->tx_l.med));
 
 	free(frame);
 }
diff --git a/monitor/packet.c b/monitor/packet.c
index f581a8e7233d..b905080edc60 100644
--- a/monitor/packet.c
+++ b/monitor/packet.c
@@ -10336,7 +10336,34 @@ static void role_change_evt(struct timeval *tv, uint16_t index,
 	print_role(evt->role);
 }
 
-#define TV_MSEC(_tv) (long long)(_tv.tv_sec * 1000 + _tv.tv_usec / 1000)
+void packet_latency_add(struct packet_latency *latency, struct timeval *delta)
+{
+	if ((!timerisset(&latency->min) || timercmp(delta, &latency->min, <))
+				&& delta->tv_sec >= 0 && delta->tv_usec >= 0)
+		latency->min = *delta;
+
+	if (!timerisset(&latency->max) || timercmp(delta, &latency->max, >))
+		latency->max = *delta;
+
+	if (timerisset(&latency->med)) {
+		struct timeval tmp;
+
+		timeradd(&latency->med, delta, &tmp);
+
+		tmp.tv_sec /= 2;
+		tmp.tv_usec /= 2;
+		if (tmp.tv_sec % 2) {
+			tmp.tv_usec += 500000;
+			if (tmp.tv_usec >= 1000000) {
+				tmp.tv_sec++;
+				tmp.tv_usec -= 1000000;
+			}
+		}
+
+		latency->med = tmp;
+	} else
+		latency->med = *delta;
+}
 
 static void packet_dequeue_tx(struct timeval *tv, uint16_t handle)
 {
@@ -10354,35 +10381,11 @@ static void packet_dequeue_tx(struct timeval *tv, uint16_t handle)
 
 	timersub(tv, tx, &delta);
 
-	if ((!timerisset(&conn->tx_min) || timercmp(&delta, &conn->tx_min, <))
-				&& delta.tv_sec >= 0 && delta.tv_usec >= 0)
-		conn->tx_min = delta;
-
-	if (!timerisset(&conn->tx_max) || timercmp(&delta, &conn->tx_max, >))
-		conn->tx_max = delta;
-
-	if (timerisset(&conn->tx_med)) {
-		struct timeval tmp;
-
-		timeradd(&conn->tx_med, &delta, &tmp);
-
-		tmp.tv_sec /= 2;
-		tmp.tv_usec /= 2;
-		if (tmp.tv_sec % 2) {
-			tmp.tv_usec += 500000;
-			if (tmp.tv_usec >= 1000000) {
-				tmp.tv_sec++;
-				tmp.tv_usec -= 1000000;
-			}
-		}
-
-		conn->tx_med = tmp;
-	} else
-		conn->tx_med = delta;
+	packet_latency_add(&conn->tx_l, &delta);
 
 	print_field("Latency: %lld msec (%lld-%lld msec ~%lld msec)",
-			TV_MSEC(delta), TV_MSEC(conn->tx_min),
-			TV_MSEC(conn->tx_max), TV_MSEC(conn->tx_med));
+			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);
 
diff --git a/monitor/packet.h b/monitor/packet.h
index 88f4c8241ff6..12cb68d508f8 100644
--- a/monitor/packet.h
+++ b/monitor/packet.h
@@ -23,6 +23,13 @@
 #define PACKET_FILTER_SHOW_A2DP_STREAM	(1 << 6)
 #define PACKET_FILTER_SHOW_MGMT_SOCKET	(1 << 7)
 #define PACKET_FILTER_SHOW_ISO_DATA	(1 << 8)
+#define TV_MSEC(_tv) (long long)((_tv).tv_sec * 1000 + (_tv).tv_usec / 1000)
+
+struct packet_latency {
+	struct timeval min;
+	struct timeval max;
+	struct timeval med;
+};
 
 struct packet_conn_data {
 	uint16_t index;
@@ -33,14 +40,13 @@ struct packet_conn_data {
 	uint8_t  dst_type;
 	struct queue *tx_q;
 	struct queue *chan_q;
-	struct timeval tx_min;
-	struct timeval tx_max;
-	struct timeval tx_med;
+	struct packet_latency tx_l;
 	void     *data;
 	void     (*destroy)(void *data);
 };
 
 struct packet_conn_data *packet_get_conn_data(uint16_t handle);
+void packet_latency_add(struct packet_latency *latency, struct timeval *delta);
 
 bool packet_has_filter(unsigned long filter);
 void packet_set_filter(unsigned long filter);
-- 
2.41.0


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

* [BlueZ PATCH v5 4/7] monitor: Fix not dequeing TX packet properly
  2023-07-28 22:42 [BlueZ PATCH v5 1/7] monitor: Use gnuplot to plot graph of Latency-Packets Luiz Augusto von Dentz
  2023-07-28 22:42 ` [BlueZ PATCH v5 2/7] monitor: Update documentation Luiz Augusto von Dentz
  2023-07-28 22:42 ` [BlueZ PATCH v5 3/7] monitor: Consolidate code around latency calculation Luiz Augusto von Dentz
@ 2023-07-28 22:42 ` Luiz Augusto von Dentz
  2023-07-28 22:42 ` [BlueZ PATCH v5 5/7] monitor: Fix not calculating latency for ISO/SCO packets Luiz Augusto von Dentz
                   ` (4 subsequent siblings)
  7 siblings, 0 replies; 9+ messages in thread
From: Luiz Augusto von Dentz @ 2023-07-28 22:42 UTC (permalink / raw)
  To: linux-bluetooth

From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>

num_completed_packets_evt contain a count for how many packets have been
completed per handle.
---
 monitor/packet.c | 6 ++++--
 1 file changed, 4 insertions(+), 2 deletions(-)

diff --git a/monitor/packet.c b/monitor/packet.c
index b905080edc60..badc9b9c7785 100644
--- a/monitor/packet.c
+++ b/monitor/packet.c
@@ -10406,6 +10406,7 @@ static void num_completed_packets_evt(struct timeval *tv, uint16_t index,
 	for (i = 0; i < evt->num_handles; i++) {
 		uint16_t handle;
 		uint16_t count;
+		int j;
 
 		if (!util_iov_pull_le16(&iov, &handle))
 			break;
@@ -10415,9 +10416,10 @@ static void num_completed_packets_evt(struct timeval *tv, uint16_t index,
 		if (!util_iov_pull_le16(&iov, &count))
 			break;
 
-		print_field("Count: %d", le16_to_cpu(evt->count));
+		print_field("Count: %d", count);
 
-		packet_dequeue_tx(tv, handle);
+		for (j = 0; j < count; j++)
+			packet_dequeue_tx(tv, handle);
 	}
 
 	if (iov.iov_len)
-- 
2.41.0


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

* [BlueZ PATCH v5 5/7] monitor: Fix not calculating latency for ISO/SCO packets
  2023-07-28 22:42 [BlueZ PATCH v5 1/7] monitor: Use gnuplot to plot graph of Latency-Packets Luiz Augusto von Dentz
                   ` (2 preceding siblings ...)
  2023-07-28 22:42 ` [BlueZ PATCH v5 4/7] monitor: Fix not dequeing TX packet properly Luiz Augusto von Dentz
@ 2023-07-28 22:42 ` Luiz Augusto von Dentz
  2023-07-28 22:42 ` [BlueZ PATCH v5 6/7] monitor/analyze: Fix not dequeing TX packet properly Luiz Augusto von Dentz
                   ` (3 subsequent siblings)
  7 siblings, 0 replies; 9+ messages in thread
From: Luiz Augusto von Dentz @ 2023-07-28 22:42 UTC (permalink / raw)
  To: linux-bluetooth

From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>

ISO/SCO packets latency was not being calculated because no connection
was assigned to them.
---
 monitor/packet.c | 24 ++++++++++++++++++++++++
 1 file changed, 24 insertions(+)

diff --git a/monitor/packet.c b/monitor/packet.c
index badc9b9c7785..b5a4fb1671b1 100644
--- a/monitor/packet.c
+++ b/monitor/packet.c
@@ -10607,6 +10607,10 @@ static void sync_conn_complete_evt(struct timeval *tv, uint16_t index,
 	print_field("RX packet length: %d", le16_to_cpu(evt->rx_pkt_len));
 	print_field("TX packet length: %d", le16_to_cpu(evt->tx_pkt_len));
 	print_air_mode(evt->air_mode);
+
+	if (evt->status == 0x00)
+		assign_handle(index, le16_to_cpu(evt->handle), evt->link_type,
+					(void *)evt->bdaddr, BDADDR_BREDR);
 }
 
 static void sync_conn_changed_evt(struct timeval *tv, uint16_t index,
@@ -11566,6 +11570,10 @@ static void le_cis_established_evt(struct timeval *tv, uint16_t index,
 	print_field("Central to Peripheral MTU: %u", le16_to_cpu(evt->c_mtu));
 	print_field("Peripheral to Central MTU: %u", le16_to_cpu(evt->p_mtu));
 	print_slot_125("ISO Interval", evt->interval);
+
+	if (!evt->status)
+		assign_handle(index, le16_to_cpu(evt->conn_handle), 0x05,
+					NULL, BDADDR_LE_PUBLIC);
 }
 
 static void le_req_cis_evt(struct timeval *tv, uint16_t index,
@@ -11604,6 +11612,14 @@ static void le_big_complete_evt(struct timeval *tv, uint16_t index,
 	print_slot_125("ISO Interval", evt->interval);
 	print_list(evt->bis_handle, size, evt->num_bis,
 				sizeof(*evt->bis_handle), print_bis_handle);
+
+	if (!evt->status) {
+		int i;
+
+		for (i = 0; i < evt->num_bis; i++)
+			assign_handle(index, le16_to_cpu(evt->bis_handle[i]),
+					0x05, NULL, BDADDR_LE_PUBLIC);
+	}
 }
 
 static void le_big_terminate_evt(struct timeval *tv, uint16_t index,
@@ -11631,6 +11647,14 @@ static void le_big_sync_estabilished_evt(struct timeval *tv, uint16_t index,
 	print_slot_125("ISO Interval", evt->interval);
 	print_list(evt->bis, size, evt->num_bis, sizeof(*evt->bis),
 						print_bis_handle);
+
+	if (!evt->status) {
+		int i;
+
+		for (i = 0; i < evt->num_bis; i++)
+			assign_handle(index, le16_to_cpu(evt->bis[i]),
+					0x05, NULL, BDADDR_LE_PUBLIC);
+	}
 }
 
 static void le_big_sync_lost_evt(struct timeval *tv, uint16_t index,
-- 
2.41.0


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

* [BlueZ PATCH v5 6/7] monitor/analyze: Fix not dequeing TX packet properly
  2023-07-28 22:42 [BlueZ PATCH v5 1/7] monitor: Use gnuplot to plot graph of Latency-Packets Luiz Augusto von Dentz
                   ` (3 preceding siblings ...)
  2023-07-28 22:42 ` [BlueZ PATCH v5 5/7] monitor: Fix not calculating latency for ISO/SCO packets Luiz Augusto von Dentz
@ 2023-07-28 22:42 ` Luiz Augusto von Dentz
  2023-07-28 22:42 ` [BlueZ PATCH v5 7/7] monitor/analyze: Fix not calculating latency for ISO/SCO packets Luiz Augusto von Dentz
                   ` (2 subsequent siblings)
  7 siblings, 0 replies; 9+ messages in thread
From: Luiz Augusto von Dentz @ 2023-07-28 22:42 UTC (permalink / raw)
  To: linux-bluetooth

From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>

num_completed_packets_evt contain a count for how many packets have been
completed per handle.
---
 monitor/analyze.c | 15 +++++++++------
 1 file changed, 9 insertions(+), 6 deletions(-)

diff --git a/monitor/analyze.c b/monitor/analyze.c
index ddaaf6942035..c8192ffa7d2a 100644
--- a/monitor/analyze.c
+++ b/monitor/analyze.c
@@ -532,6 +532,7 @@ static void evt_num_completed_packets(struct hci_dev *dev, struct timeval *tv,
 		struct hci_conn *conn;
 		struct timeval res;
 		struct timeval *last_tx;
+		int j;
 
 		data += 4;
 		size -= 4;
@@ -542,15 +543,17 @@ static void evt_num_completed_packets(struct hci_dev *dev, struct timeval *tv,
 
 		conn->tx_num_comp += count;
 
-		last_tx = queue_pop_head(conn->tx_queue);
-		if (last_tx) {
-			timersub(tv, last_tx, &res);
+		for (j = 0; j < count; j++) {
+			last_tx = queue_pop_head(conn->tx_queue);
+			if (last_tx) {
+				timersub(tv, last_tx, &res);
 
-			packet_latency_add(&conn->tx_l, &res);
+				packet_latency_add(&conn->tx_l, &res);
 
-			plot_add(conn->plot, &res, count);
+				plot_add(conn->plot, &res, count);
 
-			free(last_tx);
+				free(last_tx);
+			}
 		}
 	}
 }
-- 
2.41.0


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

* [BlueZ PATCH v5 7/7] monitor/analyze: Fix not calculating latency for ISO/SCO packets
  2023-07-28 22:42 [BlueZ PATCH v5 1/7] monitor: Use gnuplot to plot graph of Latency-Packets Luiz Augusto von Dentz
                   ` (4 preceding siblings ...)
  2023-07-28 22:42 ` [BlueZ PATCH v5 6/7] monitor/analyze: Fix not dequeing TX packet properly Luiz Augusto von Dentz
@ 2023-07-28 22:42 ` Luiz Augusto von Dentz
  2023-07-29  1:11 ` [BlueZ,v5,1/7] monitor: Use gnuplot to plot graph of Latency-Packets bluez.test.bot
  2023-07-31 17:50 ` [BlueZ PATCH v5 1/7] " patchwork-bot+bluetooth
  7 siblings, 0 replies; 9+ messages in thread
From: Luiz Augusto von Dentz @ 2023-07-28 22:42 UTC (permalink / raw)
  To: linux-bluetooth

From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>

ISO/SCO packets latency was not being calculated because no connection was
being assigned to them.
---
 monitor/analyze.c | 56 +++++++++++++++++++++++++++++++++++++++++++----
 1 file changed, 52 insertions(+), 4 deletions(-)

diff --git a/monitor/analyze.c b/monitor/analyze.c
index c8192ffa7d2a..b4a7cf726ac9 100644
--- a/monitor/analyze.c
+++ b/monitor/analyze.c
@@ -652,10 +652,28 @@ static void acl_pkt(struct timeval *tv, uint16_t index, bool out,
 	}
 }
 
-static void sco_pkt(struct timeval *tv, uint16_t index,
+static void conn_pkt_tx(struct hci_conn *conn, struct timeval *tv,
+					uint16_t size)
+{
+	struct timeval *last_tx;
+
+	last_tx = new0(struct timeval, 1);
+	memcpy(last_tx, tv, sizeof(*tv));
+	queue_push_tail(conn->tx_queue, last_tx);
+	conn->tx_bytes += size;
+
+	if (!conn->tx_pkt_min || size < conn->tx_pkt_min)
+		conn->tx_pkt_min = size;
+	if (!conn->tx_pkt_max || size > conn->tx_pkt_max)
+		conn->tx_pkt_max = size;
+}
+
+static void sco_pkt(struct timeval *tv, uint16_t index, bool out,
 					const void *data, uint16_t size)
 {
+	const struct bt_hci_acl_hdr *hdr = data;
 	struct hci_dev *dev;
+	struct hci_conn *conn;
 
 	dev = dev_lookup(index);
 	if (!dev)
@@ -663,6 +681,18 @@ static void sco_pkt(struct timeval *tv, uint16_t index,
 
 	dev->num_hci++;
 	dev->num_sco++;
+
+	conn = conn_lookup_type(dev, le16_to_cpu(hdr->handle) & 0x0fff,
+								CONN_BR_SCO);
+	if (!conn)
+		return;
+
+	if (out) {
+		conn->tx_num++;
+		conn_pkt_tx(conn, tv, size - sizeof(*hdr));
+	} else {
+		conn->rx_num++;
+	}
 }
 
 static void info_index(struct timeval *tv, uint16_t index,
@@ -726,9 +756,11 @@ static void ctrl_msg(struct timeval *tv, uint16_t index,
 	dev->ctrl_msg++;
 }
 
-static void iso_pkt(struct timeval *tv, uint16_t index,
+static void iso_pkt(struct timeval *tv, uint16_t index, bool out,
 					const void *data, uint16_t size)
 {
+	const struct bt_hci_iso_hdr *hdr = data;
+	struct hci_conn *conn;
 	struct hci_dev *dev;
 
 	dev = dev_lookup(index);
@@ -737,6 +769,18 @@ static void iso_pkt(struct timeval *tv, uint16_t index,
 
 	dev->num_hci++;
 	dev->num_iso++;
+
+	conn = conn_lookup_type(dev, le16_to_cpu(hdr->handle) & 0x0fff,
+								CONN_LE_ISO);
+	if (!conn)
+		return;
+
+	if (out) {
+		conn->tx_num++;
+		conn_pkt_tx(conn, tv, size - sizeof(*hdr));
+	} else {
+		conn->rx_num++;
+	}
 }
 
 static void unknown_opcode(struct timeval *tv, uint16_t index,
@@ -804,8 +848,10 @@ void analyze_trace(const char *path)
 			acl_pkt(&tv, index, false, buf, pktlen);
 			break;
 		case BTSNOOP_OPCODE_SCO_TX_PKT:
+			sco_pkt(&tv, index, true, buf, pktlen);
+			break;
 		case BTSNOOP_OPCODE_SCO_RX_PKT:
-			sco_pkt(&tv, index, buf, pktlen);
+			sco_pkt(&tv, index, false, buf, pktlen);
 			break;
 		case BTSNOOP_OPCODE_OPEN_INDEX:
 		case BTSNOOP_OPCODE_CLOSE_INDEX:
@@ -829,8 +875,10 @@ void analyze_trace(const char *path)
 			ctrl_msg(&tv, index, buf, pktlen);
 			break;
 		case BTSNOOP_OPCODE_ISO_TX_PKT:
+			iso_pkt(&tv, index, true, buf, pktlen);
+			break;
 		case BTSNOOP_OPCODE_ISO_RX_PKT:
-			iso_pkt(&tv, index, buf, pktlen);
+			iso_pkt(&tv, index, false, buf, pktlen);
 			break;
 		default:
 			unknown_opcode(&tv, index, buf, pktlen);
-- 
2.41.0


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

* RE: [BlueZ,v5,1/7] monitor: Use gnuplot to plot graph of Latency-Packets
  2023-07-28 22:42 [BlueZ PATCH v5 1/7] monitor: Use gnuplot to plot graph of Latency-Packets Luiz Augusto von Dentz
                   ` (5 preceding siblings ...)
  2023-07-28 22:42 ` [BlueZ PATCH v5 7/7] monitor/analyze: Fix not calculating latency for ISO/SCO packets Luiz Augusto von Dentz
@ 2023-07-29  1:11 ` bluez.test.bot
  2023-07-31 17:50 ` [BlueZ PATCH v5 1/7] " patchwork-bot+bluetooth
  7 siblings, 0 replies; 9+ messages in thread
From: bluez.test.bot @ 2023-07-29  1:11 UTC (permalink / raw)
  To: linux-bluetooth, luiz.dentz

[-- Attachment #1: Type: text/plain, Size: 4795 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=770739

---Test result---

Test Summary:
CheckPatch                    FAIL      3.33 seconds
GitLint                       PASS      2.04 seconds
BuildEll                      PASS      26.20 seconds
BluezMake                     PASS      754.54 seconds
MakeCheck                     PASS      11.28 seconds
MakeDistcheck                 PASS      152.27 seconds
CheckValgrind                 PASS      247.21 seconds
CheckSmatch                   WARNING   333.09 seconds
bluezmakeextell               PASS      100.58 seconds
IncrementalBuild              PASS      4437.75 seconds
ScanBuild                     WARNING   981.58 seconds

Details
##############################
Test: CheckPatch - FAIL
Desc: Run checkpatch.pl script
Output:
[BlueZ,v5,1/7] monitor: Use gnuplot to plot graph of Latency-Packets
WARNING:COMMIT_LOG_LONG_LINE: Possible unwrapped commit description (prefer a maximum 75 chars per line)
#86: 
        Address: XX:XX:XX:XX:XX:XX (Sony Home Entertainment&Sound Products Inc)

/github/workspace/src/src/13332712.patch total: 0 errors, 1 warnings, 156 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/13332712.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.


[BlueZ,v5,2/7] monitor: Update documentation
ERROR:CODE_INDENT: code indent should use tabs where possible
#115: FILE: monitor/main.c:55:
+                "\t                       system it will also attempt to plot\n"$

WARNING:LEADING_SPACE: please, no spaces at the start of a line
#115: FILE: monitor/main.c:55:
+                "\t                       system it will also attempt to plot\n"$

/github/workspace/src/src/13332713.patch total: 1 errors, 1 warnings, 19 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.

NOTE: Whitespace errors detected.
      You may wish to use scripts/cleanpatch or scripts/cleanfile

/github/workspace/src/src/13332713.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/l2cap.c: note: in included file:monitor/display.h:82:26: warning: Variable length array is used.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:3551:52: warning: array of flexible structuresmonitor/bt.h:3539:40: warning: array of flexible structuresmonitor/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:3551:52: warning: array of flexible structuresmonitor/bt.h:3539:40: warning: array of flexible structuresmonitor/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:3551:52: war
 ning: array of flexible structuresmonitor/bt.h:3539:40: warning: array of flexible structures
##############################
Test: ScanBuild - WARNING
Desc: Run Scan Build
Output:
monitor/l2cap.c:1638:4: warning: Value stored to 'data' is never read
                        data += len;
                        ^       ~~~
monitor/l2cap.c:1639:4: warning: Value stored to 'size' is never read
                        size -= len;
                        ^       ~~~
2 warnings generated.
monitor/packet.c:12399:2: warning: Null pointer passed to 2nd parameter expecting 'nonnull'
        memcpy(tx, tv, sizeof(*tv));
        ^~~~~~~~~~~~~~~~~~~~~~~~~~~
1 warning generated.



---
Regards,
Linux Bluetooth


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

* Re: [BlueZ PATCH v5 1/7] monitor: Use gnuplot to plot graph of Latency-Packets
  2023-07-28 22:42 [BlueZ PATCH v5 1/7] monitor: Use gnuplot to plot graph of Latency-Packets Luiz Augusto von Dentz
                   ` (6 preceding siblings ...)
  2023-07-29  1:11 ` [BlueZ,v5,1/7] monitor: Use gnuplot to plot graph of Latency-Packets bluez.test.bot
@ 2023-07-31 17:50 ` patchwork-bot+bluetooth
  7 siblings, 0 replies; 9+ messages in thread
From: patchwork-bot+bluetooth @ 2023-07-31 17:50 UTC (permalink / raw)
  To: Luiz Augusto von Dentz; +Cc: linux-bluetooth

Hello:

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

On Fri, 28 Jul 2023 15:42:41 -0700 you wrote:
> From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
> 
> This make use of gnuplot when using -a/--analyze to plot a graph of
> Latency-Packets:
> 
>   Found BR-ACL connection with handle 256
>         Address: XX:XX:XX:XX:XX:XX (Sony Home Entertainment&Sound Products Inc)
>         60 RX packets
>         22548 TX packets
>         22547 TX completed packets
>         3 msec min latency
>         73 msec max latency
>         11 msec median latency
>         6 octets TX min packet size
>         850 octets TX max packet size
>         847 octets TX median packet size
> 
> [...]

Here is the summary with links:
  - [BlueZ,v5,1/7] monitor: Use gnuplot to plot graph of Latency-Packets
    https://git.kernel.org/pub/scm/bluetooth/bluez.git/?id=ac04b56c41fe
  - [BlueZ,v5,2/7] monitor: Update documentation
    https://git.kernel.org/pub/scm/bluetooth/bluez.git/?id=9a657dcec988
  - [BlueZ,v5,3/7] monitor: Consolidate code around latency calculation
    https://git.kernel.org/pub/scm/bluetooth/bluez.git/?id=5d090ddc6aa6
  - [BlueZ,v5,4/7] monitor: Fix not dequeing TX packet properly
    https://git.kernel.org/pub/scm/bluetooth/bluez.git/?id=77fb0ab5287c
  - [BlueZ,v5,5/7] monitor: Fix not calculating latency for ISO/SCO packets
    https://git.kernel.org/pub/scm/bluetooth/bluez.git/?id=f150939419d3
  - [BlueZ,v5,6/7] monitor/analyze: Fix not dequeing TX packet properly
    https://git.kernel.org/pub/scm/bluetooth/bluez.git/?id=b4cf0900d05c
  - [BlueZ,v5,7/7] monitor/analyze: Fix not calculating latency for ISO/SCO packets
    https://git.kernel.org/pub/scm/bluetooth/bluez.git/?id=dce3971d227d

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] 9+ messages in thread

end of thread, other threads:[~2023-07-31 17:50 UTC | newest]

Thread overview: 9+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2023-07-28 22:42 [BlueZ PATCH v5 1/7] monitor: Use gnuplot to plot graph of Latency-Packets Luiz Augusto von Dentz
2023-07-28 22:42 ` [BlueZ PATCH v5 2/7] monitor: Update documentation Luiz Augusto von Dentz
2023-07-28 22:42 ` [BlueZ PATCH v5 3/7] monitor: Consolidate code around latency calculation Luiz Augusto von Dentz
2023-07-28 22:42 ` [BlueZ PATCH v5 4/7] monitor: Fix not dequeing TX packet properly Luiz Augusto von Dentz
2023-07-28 22:42 ` [BlueZ PATCH v5 5/7] monitor: Fix not calculating latency for ISO/SCO packets Luiz Augusto von Dentz
2023-07-28 22:42 ` [BlueZ PATCH v5 6/7] monitor/analyze: Fix not dequeing TX packet properly Luiz Augusto von Dentz
2023-07-28 22:42 ` [BlueZ PATCH v5 7/7] monitor/analyze: Fix not calculating latency for ISO/SCO packets Luiz Augusto von Dentz
2023-07-29  1:11 ` [BlueZ,v5,1/7] monitor: Use gnuplot to plot graph of Latency-Packets bluez.test.bot
2023-07-31 17:50 ` [BlueZ PATCH v5 1/7] " 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;
as well as URLs for NNTP newsgroup(s).