From: Luiz Augusto von Dentz <[email protected]>
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
From: Luiz Augusto von Dentz <[email protected]>
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
From: Luiz Augusto von Dentz <[email protected]>
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
From: Luiz Augusto von Dentz <[email protected]>
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
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
Hello:
This series was applied to bluetooth/bluez.git (master)
by Luiz Augusto von Dentz <[email protected]>:
On Fri, 28 Jul 2023 15:42:41 -0700 you wrote:
> From: Luiz Augusto von Dentz <[email protected]>
>
> 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