* [PATCH BlueZ v1 01/10] monitor: Reference the request frame on command responses
2026-09-09 18:28 [PATCH BlueZ v1 00/10] monitor: Reference request frames on responses Luiz Augusto von Dentz
@ 2026-09-09 18:28 ` Luiz Augusto von Dentz
2026-09-10 17:43 ` monitor: Reference request frames on responses bluez.test.bot
2026-09-09 18:28 ` [PATCH BlueZ v1 02/10] doc/btmon: Document the request reference on command responses Luiz Augusto von Dentz
` (8 subsequent siblings)
9 siblings, 1 reply; 12+ messages in thread
From: Luiz Augusto von Dentz @ 2026-09-09 18:28 UTC (permalink / raw)
To: linux-bluetooth
From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
Correlating a Command Complete or a Command Status with the command it
responds to means scrolling back through the trace to find the matching
opcode, and the time the controller took to respond is not visible at all
without comparing timestamps by hand.
Keep the frame number and the timestamp of each command that has not been
answered yet, and append both to the opcode line of the response, so that
a slow command is obvious at the point where it completes:
< HCI Command: LE Set Random Address (0x08|0x0005) plen 6 #76 [hci0] 3.175055
Address: 00:11:22:33:44:55 (Non-Resolvable)
> HCI Event: Command Complete (0x0e) plen 4 #77 [hci0] 3.175394
LE Set Random Address (0x08|0x0005) ncmd 1 #76 (0.339 msec)
Status: Success (0x00)
Several commands may be outstanding at once and they need not complete in
order, so entries are matched on the opcode and the oldest one is taken.
Nothing is printed when the request was not captured, which is the normal
case when attaching to a system that is already running. The queue is
bounded so commands that never get a response cannot pile up, and it is
released when the index goes away.
The model wrote the tracking and the matching, which the author reviewed
and verified against traces covering out of order completion, a response
without a request and sub-millisecond deltas.
Assisted-by: opencode:claude-opus-5
---
monitor/packet.c | 108 +++++++++++++++++++++++++++++++++++++++++++++--
1 file changed, 104 insertions(+), 4 deletions(-)
diff --git a/monitor/packet.c b/monitor/packet.c
index db52eb789629..2b238e550b58 100644
--- a/monitor/packet.c
+++ b/monitor/packet.c
@@ -147,6 +147,7 @@ struct index_data {
uint8_t msft_evt_prefix[8];
uint8_t msft_evt_len;
size_t frame;
+ struct queue *cmd_q;
struct index_buf_pool acl;
struct index_buf_pool sco;
struct index_buf_pool le;
@@ -155,6 +156,85 @@ struct index_data {
static struct index_data index_list[MAX_INDEX];
+/*
+ * Commands awaiting a Command Complete or a Command Status, so that the
+ * response can point back at the frame that carried the request.
+ */
+struct pending_cmd {
+ uint16_t opcode;
+ size_t frame;
+ struct timeval tv;
+};
+
+/* Bound the queue so commands that never get a response cannot pile up */
+#define PENDING_CMD_MAX 64
+
+static bool match_pending_cmd(const void *data, const void *user_data)
+{
+ const struct pending_cmd *cmd = data;
+
+ return cmd->opcode == PTR_TO_UINT(user_data);
+}
+
+static void pending_cmd_enqueue(uint16_t index, uint16_t opcode,
+ struct timeval *tv)
+{
+ struct index_data *ctrl = &index_list[index];
+ struct pending_cmd *cmd;
+
+ if (!ctrl->cmd_q)
+ ctrl->cmd_q = queue_new();
+
+ if (queue_length(ctrl->cmd_q) >= PENDING_CMD_MAX)
+ free(queue_pop_head(ctrl->cmd_q));
+
+ cmd = new0(struct pending_cmd, 1);
+ cmd->opcode = opcode;
+ cmd->frame = ctrl->frame;
+ if (tv)
+ cmd->tv = *tv;
+
+ queue_push_tail(ctrl->cmd_q, cmd);
+}
+
+/*
+ * Format the request reference for a response, as the frame number of the
+ * command and the time elapsed since it was sent. Leaves the string empty
+ * when the request was not seen, which is the normal case for a capture
+ * started while commands were already in flight.
+ */
+static void pending_cmd_str(uint16_t index, uint16_t opcode,
+ struct timeval *tv, char *str, size_t len)
+{
+ struct pending_cmd *cmd;
+ struct timeval delta;
+
+ str[0] = '\0';
+
+ if (index >= MAX_INDEX)
+ return;
+
+ /*
+ * Several commands may be outstanding at once and they need not
+ * complete in order, so match on the opcode and take the oldest.
+ */
+ cmd = queue_remove_if(index_list[index].cmd_q, match_pending_cmd,
+ UINT_TO_PTR(opcode));
+ if (!cmd)
+ return;
+
+ if (tv && timerisset(&cmd->tv)) {
+ timersub(tv, &cmd->tv, &delta);
+ snprintf(str, len, " #%zu (%lld.%03lld msec)", cmd->frame,
+ (long long)delta.tv_sec * 1000 +
+ delta.tv_usec / 1000,
+ (long long)delta.tv_usec % 1000);
+ } else
+ snprintf(str, len, " #%zu", cmd->frame);
+
+ free(cmd);
+}
+
static void assign_ctrl(uint32_t cookie, uint16_t format, const char *name)
{
int i;
@@ -11357,9 +11437,11 @@ static void cmd_complete_evt(struct timeval *tv, uint16_t index,
struct opcode_data vendor_data;
const struct opcode_data *opcode_data = NULL;
const char *opcode_color, *opcode_str;
- char vendor_str[150];
+ char vendor_str[150], req_str[32];
int i;
+ pending_cmd_str(index, opcode, tv, req_str, sizeof(req_str));
+
for (i = 0; opcode_table[i].str; i++) {
if (opcode_table[i].opcode == opcode) {
opcode_data = &opcode_table[i];
@@ -11408,7 +11490,8 @@ static void cmd_complete_evt(struct timeval *tv, uint16_t index,
}
print_indent(6, opcode_color, "", opcode_str, COLOR_OFF,
- " (0x%2.2x|0x%4.4x) ncmd %d", ogf, ocf, evt->ncmd);
+ " (0x%2.2x|0x%4.4x) ncmd %d%s", ogf, ocf, evt->ncmd,
+ req_str);
if (!opcode_data || !opcode_data->rsp_func) {
if (size > 3) {
@@ -11453,9 +11536,11 @@ static void cmd_status_evt(struct timeval *tv, uint16_t index,
uint16_t ocf = cmd_opcode_ocf(opcode);
const struct opcode_data *opcode_data = NULL;
const char *opcode_color, *opcode_str;
- char vendor_str[150];
+ char vendor_str[150], req_str[32];
int i;
+ pending_cmd_str(index, opcode, tv, req_str, sizeof(req_str));
+
for (i = 0; opcode_table[i].str; i++) {
if (opcode_table[i].opcode == opcode) {
opcode_data = &opcode_table[i];
@@ -11492,7 +11577,8 @@ static void cmd_status_evt(struct timeval *tv, uint16_t index,
}
print_indent(6, opcode_color, "", opcode_str, COLOR_OFF,
- " (0x%2.2x|0x%4.4x) ncmd %d", ogf, ocf, evt->ncmd);
+ " (0x%2.2x|0x%4.4x) ncmd %d%s", ogf, ocf, evt->ncmd,
+ req_str);
print_status(evt->status);
}
@@ -14086,6 +14172,11 @@ void packet_del_index(struct timeval *tv, uint16_t index, const char *label)
{
print_packet(tv, NULL, '=', index, NULL, COLOR_DEL_INDEX,
"Delete Index", label, NULL);
+
+ if (index < MAX_INDEX) {
+ queue_destroy(index_list[index].cmd_q, free);
+ index_list[index].cmd_q = NULL;
+ }
}
void packet_open_index(struct timeval *tv, uint16_t index, const char *label)
@@ -14098,6 +14189,11 @@ void packet_close_index(struct timeval *tv, uint16_t index, const char *label)
{
print_packet(tv, NULL, '=', index, NULL, COLOR_CLOSE_INDEX,
"Close Index", label, NULL);
+
+ if (index < MAX_INDEX) {
+ queue_destroy(index_list[index].cmd_q, free);
+ index_list[index].cmd_q = NULL;
+ }
}
void packet_index_info(struct timeval *tv, uint16_t index, const char *label,
@@ -14249,6 +14345,10 @@ void packet_hci_command(struct timeval *tv, struct ucred *cred, uint16_t index,
data += HCI_COMMAND_HDR_SIZE;
size -= HCI_COMMAND_HDR_SIZE;
+ /* NOP carries no request and is only used to update ncmd */
+ if (opcode != BT_HCI_CMD_NOP)
+ pending_cmd_enqueue(index, opcode, tv);
+
for (i = 0; opcode_table[i].str; i++) {
if (opcode_table[i].opcode == opcode) {
opcode_data = &opcode_table[i];
--
2.55.0
^ permalink raw reply related [flat|nested] 12+ messages in thread* [PATCH BlueZ v1 02/10] doc/btmon: Document the request reference on command responses
2026-09-09 18:28 [PATCH BlueZ v1 00/10] monitor: Reference request frames on responses Luiz Augusto von Dentz
2026-09-09 18:28 ` [PATCH BlueZ v1 01/10] monitor: Reference the request frame on command responses Luiz Augusto von Dentz
@ 2026-09-09 18:28 ` Luiz Augusto von Dentz
2026-09-09 18:28 ` [PATCH BlueZ v1 03/10] monitor: Resolve commands completed by a later event Luiz Augusto von Dentz
` (7 subsequent siblings)
9 siblings, 0 replies; 12+ messages in thread
From: Luiz Augusto von Dentz @ 2026-09-09 18:28 UTC (permalink / raw)
To: linux-bluetooth
From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
Extend the Command Complete example to show the request frame number and
the response time, and describe how the reference is resolved and when it
is omitted.
The model drafted the text, which the author reviewed against the actual
output.
Assisted-by: opencode:claude-opus-5
---
doc/btmon.rst | 14 +++++++++++++-
1 file changed, 13 insertions(+), 1 deletion(-)
diff --git a/doc/btmon.rst b/doc/btmon.rst
index adb2c9881f97..99d6c8ae2760 100644
--- a/doc/btmon.rst
+++ b/doc/btmon.rst
@@ -232,14 +232,26 @@ input going into the controller, ``>`` is output coming from it.
**HCI event responses** reference the command they complete::
+ < HCI Command: Reset (0x03|0x0003) plen 0 #5 [hci0] 12:35:01.843185
> HCI Event: Command Complete (0x0e) plen 4 #6 [hci0] 12:35:01.864922
- Reset (0x03|0x0003) ncmd 2
+ Reset (0x03|0x0003) ncmd 2 #5 (21.737 msec)
Status: Success (0x00)
Here ``ncmd 2`` indicates the controller can accept 2 more commands
(HCI flow control). The indented body shows the command this event
completes and the result status.
+The trailing ``#5 (21.737 msec)`` is the frame number of the command that
+this event responds to, and how long the controller took to respond. It
+saves scrolling back through the trace to find the request, and makes a
+slow command obvious at the point where it completes.
+
+Several commands may be outstanding at once and they need not complete in
+order, so the reference is resolved by opcode, oldest first. It is omitted
+when the request was not captured, which is normal for the first commands
+seen when attaching to a system that is already running. ``Command Status``
+events carry the same reference.
+
**LE Meta Events** contain a subevent type::
> HCI Event: LE Meta Event (0x3e) plen 31 #487 [hci0] 12:36:18.974201
--
2.55.0
^ permalink raw reply related [flat|nested] 12+ messages in thread* [PATCH BlueZ v1 03/10] monitor: Resolve commands completed by a later event
2026-09-09 18:28 [PATCH BlueZ v1 00/10] monitor: Reference request frames on responses Luiz Augusto von Dentz
2026-09-09 18:28 ` [PATCH BlueZ v1 01/10] monitor: Reference the request frame on command responses Luiz Augusto von Dentz
2026-09-09 18:28 ` [PATCH BlueZ v1 02/10] doc/btmon: Document the request reference on command responses Luiz Augusto von Dentz
@ 2026-09-09 18:28 ` Luiz Augusto von Dentz
2026-09-09 18:28 ` [PATCH BlueZ v1 04/10] doc/btmon: Document the deferred command references Luiz Augusto von Dentz
` (6 subsequent siblings)
9 siblings, 0 replies; 12+ messages in thread
From: Luiz Augusto von Dentz @ 2026-09-09 18:28 UTC (permalink / raw)
To: linux-bluetooth
From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
Some commands are only acknowledged by a Command Status and complete much
later through a separate event. Create Connection, Remote Name Request and
LE Create Connection are the common ones, and the delay is often seconds,
so this is exactly where the request reference is worth having. Until now
the completing event carried no hint of which command caused it:
> HCI Event: Connect Complete (0x03) plen 11 #27 [hci0] 6.178055
Request: #12 (3003.000 msec)
Status: Success (0x00)
Handle: 12
Address: 00:11:22:33:44:55 (CIMSYS Inc)
Keep such commands queued past their Command Status and resolve them when
the completing event arrives, using a table that maps the opcode to the
event and to the value the two are matched on. Several may be outstanding
towards different devices at once and need not complete in order, so the
match is on the connection handle or the remote address, not on the opcode
alone. Inquiry and the LE connection commands are matched on the opcode
only, since the specification allows a single one to be outstanding and
the address in the command is ignored when the accept list is in use.
A Command Status reporting an error means the completing event will never
arrive, so the command is dropped instead of being left to match a later
unrelated event.
Setup Synchronous Connection and LE Create CIS are deliberately left out.
The former reports the ACL handle in the command but the new synchronous
handle in the event, and the latter produces one event per CIS, so neither
can be matched this way without being wrong.
The model wrote the table and the matching, which the author reviewed and
verified against traces covering out of order completion of two commands
with the same opcode, handle and address keyed matching, a failing Command
Status and truncated events.
Assisted-by: opencode:claude-opus-5
---
monitor/packet.c | 303 +++++++++++++++++++++++++++++++++++++++++------
1 file changed, 266 insertions(+), 37 deletions(-)
diff --git a/monitor/packet.c b/monitor/packet.c
index 2b238e550b58..053c1165bf99 100644
--- a/monitor/packet.c
+++ b/monitor/packet.c
@@ -156,6 +156,13 @@ struct index_data {
static struct index_data index_list[MAX_INDEX];
+/* How a deferred command is tied to the event that completes it */
+enum pending_key {
+ PENDING_KEY_NONE, /* Only one may be outstanding at a time */
+ PENDING_KEY_HANDLE,
+ PENDING_KEY_BDADDR,
+};
+
/*
* Commands awaiting a Command Complete or a Command Status, so that the
* response can point back at the frame that carried the request.
@@ -164,23 +171,190 @@ struct pending_cmd {
uint16_t opcode;
size_t frame;
struct timeval tv;
+ bool deferred; /* Completed by an event, not by the status */
+ bool acked; /* A Command Status has been seen already */
+ uint8_t key_type;
+ uint8_t key[6];
};
/* Bound the queue so commands that never get a response cannot pile up */
#define PENDING_CMD_MAX 64
+/*
+ * Commands that are only acknowledged by a Command Status and complete
+ * later through a separate event. The key ties a pending command to its
+ * event when more than one may be outstanding, and the offsets are into
+ * the command and the event parameters respectively.
+ */
+struct deferred_data {
+ uint16_t opcode;
+ uint8_t evt;
+ uint8_t subevt; /* Only used when evt is LE Meta Event */
+ uint8_t key_type;
+ uint8_t cmd_off;
+ uint8_t evt_off;
+};
+
+static const struct deferred_data deferred_table[] = {
+ /* Keyed on the connection handle */
+ { BT_HCI_CMD_DISCONNECT, 0x05, 0x00, PENDING_KEY_HANDLE, 0, 1 },
+ { BT_HCI_CMD_AUTH_REQUESTED, 0x06, 0x00, PENDING_KEY_HANDLE, 0, 1 },
+ { BT_HCI_CMD_SET_CONN_ENCRYPT, 0x08, 0x00, PENDING_KEY_HANDLE, 0, 1 },
+ { BT_HCI_CMD_SET_CONN_ENCRYPT, 0x59, 0x00, PENDING_KEY_HANDLE, 0, 1 },
+ { BT_HCI_CMD_READ_REMOTE_FEATURES, 0x0b, 0x00,
+ PENDING_KEY_HANDLE, 0, 1 },
+ { BT_HCI_CMD_READ_REMOTE_EXT_FEATURES, 0x23, 0x00,
+ PENDING_KEY_HANDLE, 0, 1 },
+ { BT_HCI_CMD_READ_REMOTE_VERSION, 0x0c, 0x00,
+ PENDING_KEY_HANDLE, 0, 1 },
+ { BT_HCI_CMD_READ_CLOCK_OFFSET, 0x1c, 0x00,
+ PENDING_KEY_HANDLE, 0, 1 },
+ { BT_HCI_CMD_LE_READ_REMOTE_FEATURES, 0x3e, 0x04,
+ PENDING_KEY_HANDLE, 0, 1 },
+ { BT_HCI_CMD_LE_START_ENCRYPT, 0x08, 0x00, PENDING_KEY_HANDLE, 0, 1 },
+ { BT_HCI_CMD_LE_START_ENCRYPT, 0x59, 0x00, PENDING_KEY_HANDLE, 0, 1 },
+ /* Keyed on the remote address */
+ { BT_HCI_CMD_CREATE_CONN, 0x03, 0x00, PENDING_KEY_BDADDR, 0, 3 },
+ { BT_HCI_CMD_ACCEPT_CONN_REQUEST, 0x03, 0x00,
+ PENDING_KEY_BDADDR, 0, 3 },
+ { BT_HCI_CMD_REMOTE_NAME_REQUEST, 0x07, 0x00,
+ PENDING_KEY_BDADDR, 0, 1 },
+ /*
+ * Not keyed, as the specification only allows one of these to be
+ * outstanding at a time. The address in the command cannot be used
+ * because it is ignored when the accept list is in use.
+ */
+ { BT_HCI_CMD_INQUIRY, 0x01, 0x00, PENDING_KEY_NONE, 0, 0 },
+ { BT_HCI_CMD_LE_CREATE_CONN, 0x3e, 0x01, PENDING_KEY_NONE, 0, 0 },
+ { BT_HCI_CMD_LE_CREATE_CONN, 0x3e, 0x0a, PENDING_KEY_NONE, 0, 0 },
+ { BT_HCI_CMD_LE_EXT_CREATE_CONN, 0x3e, 0x01, PENDING_KEY_NONE, 0, 0 },
+ { BT_HCI_CMD_LE_EXT_CREATE_CONN, 0x3e, 0x0a, PENDING_KEY_NONE, 0, 0 },
+ { }
+};
+
+static const struct deferred_data *deferred_lookup_opcode(uint16_t opcode)
+{
+ int i;
+
+ for (i = 0; deferred_table[i].opcode; i++) {
+ if (deferred_table[i].opcode == opcode)
+ return &deferred_table[i];
+ }
+
+ return NULL;
+}
+
+/*
+ * Extract the value a pending command is matched on. Handles are masked
+ * since the event carries them without the data flags.
+ */
+static bool deferred_key(uint8_t key_type, const void *data, uint8_t size,
+ uint8_t off, uint8_t *key)
+{
+ switch (key_type) {
+ case PENDING_KEY_NONE:
+ return true;
+ case PENDING_KEY_HANDLE:
+ if (size < off + 2U)
+ return false;
+ put_le16(get_le16(data + off) & 0x0fff, key);
+ return true;
+ case PENDING_KEY_BDADDR:
+ if (size < off + 6U)
+ return false;
+ memcpy(key, data + off, 6);
+ return true;
+ }
+
+ return false;
+}
+
static bool match_pending_cmd(const void *data, const void *user_data)
{
const struct pending_cmd *cmd = data;
- return cmd->opcode == PTR_TO_UINT(user_data);
+ /*
+ * A deferred command stays queued after its Command Status, so skip
+ * the ones already acknowledged or a second command with the same
+ * opcode would match the first one again.
+ */
+ return cmd->opcode == PTR_TO_UINT(user_data) && !cmd->acked;
+}
+
+struct pending_match {
+ uint16_t opcode;
+ const uint8_t *key;
+};
+
+static bool match_deferred_cmd(const void *data, const void *user_data)
+{
+ const struct pending_cmd *cmd = data;
+ const struct pending_match *match = user_data;
+
+ return cmd->opcode == match->opcode && cmd->deferred &&
+ !memcmp(cmd->key, match->key, sizeof(cmd->key));
+}
+
+static struct pending_cmd *pending_cmd_find(uint16_t index, uint16_t opcode)
+{
+ if (index >= MAX_INDEX)
+ return NULL;
+
+ /*
+ * Several commands may be outstanding at once and they need not
+ * complete in order, so match on the opcode and take the oldest.
+ */
+ return queue_find(index_list[index].cmd_q, match_pending_cmd,
+ UINT_TO_PTR(opcode));
+}
+
+static void pending_cmd_remove(uint16_t index, struct pending_cmd *cmd)
+{
+ if (index >= MAX_INDEX)
+ return;
+
+ queue_remove(index_list[index].cmd_q, cmd);
+ free(cmd);
+}
+
+/*
+ * Format the request reference for a response, as the frame number of the
+ * command and the time elapsed since it was sent. Leaves the string empty
+ * when the request was not seen, which is the normal case for a capture
+ * started while commands were already in flight.
+ */
+static void pending_cmd_str(struct pending_cmd *cmd, struct timeval *tv,
+ char *str, size_t len)
+{
+ struct timeval delta;
+
+ if (!cmd) {
+ str[0] = '\0';
+ return;
+ }
+
+ if (tv && timerisset(&cmd->tv)) {
+ timersub(tv, &cmd->tv, &delta);
+ snprintf(str, len, "#%zu (%lld.%03lld msec)", cmd->frame,
+ (long long)delta.tv_sec * 1000 +
+ delta.tv_usec / 1000,
+ (long long)delta.tv_usec % 1000);
+ } else
+ snprintf(str, len, "#%zu", cmd->frame);
}
static void pending_cmd_enqueue(uint16_t index, uint16_t opcode,
- struct timeval *tv)
+ struct timeval *tv, const void *data, uint8_t size)
{
struct index_data *ctrl = &index_list[index];
+ const struct deferred_data *deferred;
struct pending_cmd *cmd;
+ uint8_t key[6] = {};
+
+ deferred = deferred_lookup_opcode(opcode);
+ if (deferred && !deferred_key(deferred->key_type, data, size,
+ deferred->cmd_off, key))
+ deferred = NULL;
if (!ctrl->cmd_q)
ctrl->cmd_q = queue_new();
@@ -194,45 +368,61 @@ static void pending_cmd_enqueue(uint16_t index, uint16_t opcode,
if (tv)
cmd->tv = *tv;
+ if (deferred) {
+ cmd->deferred = true;
+ cmd->key_type = deferred->key_type;
+ memcpy(cmd->key, key, sizeof(key));
+ }
+
queue_push_tail(ctrl->cmd_q, cmd);
}
/*
- * Format the request reference for a response, as the frame number of the
- * command and the time elapsed since it was sent. Leaves the string empty
- * when the request was not seen, which is the normal case for a capture
- * started while commands were already in flight.
+ * Resolve the command that an event completes, for the commands that are
+ * only acknowledged by a Command Status and finish later through a
+ * separate event.
*/
-static void pending_cmd_str(uint16_t index, uint16_t opcode,
+static void deferred_cmd_str(uint16_t index, uint8_t evt, uint8_t subevt,
+ const void *data, uint8_t size,
struct timeval *tv, char *str, size_t len)
{
- struct pending_cmd *cmd;
- struct timeval delta;
+ int i;
str[0] = '\0';
if (index >= MAX_INDEX)
return;
- /*
- * Several commands may be outstanding at once and they need not
- * complete in order, so match on the opcode and take the oldest.
- */
- cmd = queue_remove_if(index_list[index].cmd_q, match_pending_cmd,
- UINT_TO_PTR(opcode));
- if (!cmd)
+ for (i = 0; deferred_table[i].opcode; i++) {
+ const struct deferred_data *deferred = &deferred_table[i];
+ struct pending_match match;
+ struct pending_cmd *cmd;
+ uint8_t key[6] = {};
+
+ if (deferred->evt != evt || deferred->subevt != subevt)
+ continue;
+
+ if (!deferred_key(deferred->key_type, data, size,
+ deferred->evt_off, key))
+ continue;
+
+ /*
+ * Match on the key as well as the opcode, since several of
+ * these may be outstanding towards different devices and
+ * they need not complete in order.
+ */
+ match.opcode = deferred->opcode;
+ match.key = key;
+
+ cmd = queue_find(index_list[index].cmd_q, match_deferred_cmd,
+ &match);
+ if (!cmd)
+ continue;
+
+ pending_cmd_str(cmd, tv, str, len);
+ pending_cmd_remove(index, cmd);
return;
-
- if (tv && timerisset(&cmd->tv)) {
- timersub(tv, &cmd->tv, &delta);
- snprintf(str, len, " #%zu (%lld.%03lld msec)", cmd->frame,
- (long long)delta.tv_sec * 1000 +
- delta.tv_usec / 1000,
- (long long)delta.tv_usec % 1000);
- } else
- snprintf(str, len, " #%zu", cmd->frame);
-
- free(cmd);
+ }
}
static void assign_ctrl(uint32_t cookie, uint16_t format, const char *name)
@@ -11438,9 +11628,14 @@ static void cmd_complete_evt(struct timeval *tv, uint16_t index,
const struct opcode_data *opcode_data = NULL;
const char *opcode_color, *opcode_str;
char vendor_str[150], req_str[32];
+ struct pending_cmd *cmd;
int i;
- pending_cmd_str(index, opcode, tv, req_str, sizeof(req_str));
+ cmd = pending_cmd_find(index, opcode);
+ pending_cmd_str(cmd, tv, req_str, sizeof(req_str));
+ /* A Command Complete always terminates the command */
+ if (cmd)
+ pending_cmd_remove(index, cmd);
for (i = 0; opcode_table[i].str; i++) {
if (opcode_table[i].opcode == opcode) {
@@ -11490,8 +11685,8 @@ static void cmd_complete_evt(struct timeval *tv, uint16_t index,
}
print_indent(6, opcode_color, "", opcode_str, COLOR_OFF,
- " (0x%2.2x|0x%4.4x) ncmd %d%s", ogf, ocf, evt->ncmd,
- req_str);
+ " (0x%2.2x|0x%4.4x) ncmd %d%s%s", ogf, ocf, evt->ncmd,
+ req_str[0] ? " " : "", req_str);
if (!opcode_data || !opcode_data->rsp_func) {
if (size > 3) {
@@ -11537,9 +11732,22 @@ static void cmd_status_evt(struct timeval *tv, uint16_t index,
const struct opcode_data *opcode_data = NULL;
const char *opcode_color, *opcode_str;
char vendor_str[150], req_str[32];
+ struct pending_cmd *cmd;
int i;
- pending_cmd_str(index, opcode, tv, req_str, sizeof(req_str));
+ cmd = pending_cmd_find(index, opcode);
+ pending_cmd_str(cmd, tv, req_str, sizeof(req_str));
+ /*
+ * A deferred command is only acknowledged here and completes later
+ * through an event, so keep it queued. A failed status means that
+ * event will never arrive.
+ */
+ if (cmd) {
+ if (cmd->deferred && !evt->status)
+ cmd->acked = true;
+ else
+ pending_cmd_remove(index, cmd);
+ }
for (i = 0; opcode_table[i].str; i++) {
if (opcode_table[i].opcode == opcode) {
@@ -11577,8 +11785,8 @@ static void cmd_status_evt(struct timeval *tv, uint16_t index,
}
print_indent(6, opcode_color, "", opcode_str, COLOR_OFF,
- " (0x%2.2x|0x%4.4x) ncmd %d%s", ogf, ocf, evt->ncmd,
- req_str);
+ " (0x%2.2x|0x%4.4x) ncmd %d%s%s", ogf, ocf, evt->ncmd,
+ req_str[0] ? " " : "", req_str);
print_status(evt->status);
}
@@ -13764,7 +13972,8 @@ struct subevent_data {
static void print_subevent(struct timeval *tv, uint16_t index,
const struct subevent_data *subevent_data,
- const void *data, uint8_t size)
+ const void *data, uint8_t size,
+ const char *req_str)
{
const char *subevent_color;
@@ -13776,6 +13985,9 @@ static void print_subevent(struct timeval *tv, uint16_t index,
print_indent(6, subevent_color, "", subevent_data->str, COLOR_OFF,
" (0x%2.2x)", subevent_data->subevent);
+ if (req_str && req_str[0])
+ print_field("Request: %s", req_str);
+
if (!subevent_data->func) {
packet_hexdump(data, size);
return;
@@ -13932,6 +14144,7 @@ static void le_meta_event_evt(struct timeval *tv, uint16_t index,
uint8_t subevent = *((const uint8_t *) data);
struct subevent_data unknown;
const struct subevent_data *subevent_data = &unknown;
+ char req_str[32];
int i;
unknown.subevent = subevent;
@@ -13947,7 +14160,10 @@ static void le_meta_event_evt(struct timeval *tv, uint16_t index,
}
}
- print_subevent(tv, index, subevent_data, data + 1, size - 1);
+ deferred_cmd_str(index, BT_HCI_EVT_LE_META_EVENT, subevent, data + 1,
+ size - 1, tv, req_str, sizeof(req_str));
+
+ print_subevent(tv, index, subevent_data, data + 1, size - 1, req_str);
}
static void vendor_evt(struct timeval *tv, uint16_t index,
@@ -13976,7 +14192,7 @@ static void vendor_evt(struct timeval *tv, uint16_t index,
vendor_data.fixed = vnd->evt_fixed;
print_subevent(tv, index, &vendor_data, data + consumed_size,
- size - consumed_size);
+ size - consumed_size, NULL);
} else {
uint16_t manufacturer;
@@ -14347,7 +14563,7 @@ void packet_hci_command(struct timeval *tv, struct ucred *cred, uint16_t index,
/* NOP carries no request and is only used to update ncmd */
if (opcode != BT_HCI_CMD_NOP)
- pending_cmd_enqueue(index, opcode, tv);
+ pending_cmd_enqueue(index, opcode, tv, data, hdr->plen);
for (i = 0; opcode_table[i].str; i++) {
if (opcode_table[i].opcode == opcode) {
@@ -14507,6 +14723,19 @@ void packet_hci_event(struct timeval *tv, struct ucred *cred, uint16_t index,
}
}
+ /*
+ * LE Meta Events are resolved once the subevent is known, so that
+ * the reference can be printed under it.
+ */
+ if (hdr->evt != BT_HCI_EVT_LE_META_EVENT) {
+ char req_str[32];
+
+ deferred_cmd_str(index, hdr->evt, 0x00, data, hdr->plen, tv,
+ req_str, sizeof(req_str));
+ if (req_str[0])
+ print_field("Request: %s", req_str);
+ }
+
event_data->func(tv, index, data, hdr->plen);
}
--
2.55.0
^ permalink raw reply related [flat|nested] 12+ messages in thread* [PATCH BlueZ v1 04/10] doc/btmon: Document the deferred command references
2026-09-09 18:28 [PATCH BlueZ v1 00/10] monitor: Reference request frames on responses Luiz Augusto von Dentz
` (2 preceding siblings ...)
2026-09-09 18:28 ` [PATCH BlueZ v1 03/10] monitor: Resolve commands completed by a later event Luiz Augusto von Dentz
@ 2026-09-09 18:28 ` Luiz Augusto von Dentz
2026-09-09 18:28 ` [PATCH BlueZ v1 05/10] monitor: Report command latency in analyze mode Luiz Augusto von Dentz
` (5 subsequent siblings)
9 siblings, 0 replies; 12+ messages in thread
From: Luiz Augusto von Dentz @ 2026-09-09 18:28 UTC (permalink / raw)
To: linux-bluetooth
From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
Describe the Request field shown on events that complete a command which
was only acknowledged by a Command Status, and how those are matched.
The model drafted the text, which the author reviewed against the actual
output.
Assisted-by: opencode:claude-opus-5
---
doc/btmon.rst | 23 +++++++++++++++++++++++
1 file changed, 23 insertions(+)
diff --git a/doc/btmon.rst b/doc/btmon.rst
index 99d6c8ae2760..c8611ab2e9e7 100644
--- a/doc/btmon.rst
+++ b/doc/btmon.rst
@@ -252,6 +252,29 @@ when the request was not captured, which is normal for the first commands
seen when attaching to a system that is already running. ``Command Status``
events carry the same reference.
+Some commands are only acknowledged by a ``Command Status`` and complete
+much later through a separate event. Those events carry the reference as a
+``Request`` field instead::
+
+ < HCI Command: Create Connection (0x01|0x0005) plen 13 #12 [hci0] 3.175055
+ Address: 00:11:22:33:44:55 (CIMSYS Inc)
+ > HCI Event: Command Status (0x0f) plen 4 #13 [hci0] 3.176055
+ Create Connection (0x01|0x0005) ncmd 1 #12 (1.000 msec)
+ > HCI Event: Connect Complete (0x03) plen 11 #27 [hci0] 6.178055
+ Request: #12 (3003.000 msec)
+ Status: Success (0x00)
+
+This is where the reference is most useful, since the delay between the
+command and its completing event is often seconds and is otherwise only
+visible by comparing timestamps by hand. Page timeouts, slow authentication
+and slow encryption setup all show up directly.
+
+Commands of this kind are matched to their event by connection handle or by
+remote address, so several may be outstanding towards different devices at
+once and still resolve correctly. A ``Command Status`` reporting an error
+means the completing event will never arrive, and the command is dropped
+rather than left to match a later unrelated event.
+
**LE Meta Events** contain a subevent type::
> HCI Event: LE Meta Event (0x3e) plen 31 #487 [hci0] 12:36:18.974201
--
2.55.0
^ permalink raw reply related [flat|nested] 12+ messages in thread* [PATCH BlueZ v1 05/10] monitor: Report command latency in analyze mode
2026-09-09 18:28 [PATCH BlueZ v1 00/10] monitor: Reference request frames on responses Luiz Augusto von Dentz
` (3 preceding siblings ...)
2026-09-09 18:28 ` [PATCH BlueZ v1 04/10] doc/btmon: Document the deferred command references Luiz Augusto von Dentz
@ 2026-09-09 18:28 ` Luiz Augusto von Dentz
2026-09-09 18:28 ` [PATCH BlueZ v1 06/10] doc/btmon: Document the command latency statistics Luiz Augusto von Dentz
` (4 subsequent siblings)
9 siblings, 0 replies; 12+ messages in thread
From: Luiz Augusto von Dentz @ 2026-09-09 18:28 UTC (permalink / raw)
To: linux-bluetooth
From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
A trace shows every command and every response, but not how quickly the
controller answered, and a command that was never answered at all leaves
no trace beyond its absence.
Measure the interval between a command and the Command Complete or
Command Status that acknowledges it, and report it per controller along
with the number of commands still unanswered at the end of the trace:
Command latency: 0-215 msec (~55 msec +/- 70 msec)
Commands without response: 3
Commands that are only acknowledged by a Command Status and complete much
later through a separate event are measured up to the acknowledgement
only. A Create Connection waiting three seconds for its Connect Complete
is waiting on the remote device, not on the controller, and folding that
in would swamp both the average and the deviation and leave the figure
describing how many connections the trace happened to contain.
Commands are matched on the opcode, oldest first, since several may be
outstanding at once and they need not complete in order. The queue is
bounded so commands that never get a response cannot pile up.
The model wrote the tracking, which the author reviewed and verified
against a trace with a known latency spread and known unanswered
commands.
Assisted-by: opencode:claude-opus-5
---
monitor/analyze.c | 99 +++++++++++++++++++++++++++++++++++++++++++++++
1 file changed, 99 insertions(+)
diff --git a/monitor/analyze.c b/monitor/analyze.c
index 9742981ec21a..59c7e91b8758 100644
--- a/monitor/analyze.c
+++ b/monitor/analyze.c
@@ -57,8 +57,20 @@ struct hci_dev {
unsigned long unknown;
uint16_t manufacturer;
struct queue *conn_list;
+ struct queue *cmd_list;
+ struct packet_latency cmd_latency;
+ unsigned long num_cmd_rsp;
};
+/* Command awaiting a Command Complete or a Command Status */
+struct hci_cmd {
+ uint16_t opcode;
+ struct timeval tv;
+};
+
+/* Bound the queue so commands that never get a response cannot pile up */
+#define CMD_LIST_MAX 64
+
struct hci_stats {
size_t bytes;
size_t num;
@@ -488,6 +500,21 @@ static void dev_destroy(void *data)
printf(" %lu user logs\n", dev->user_log);
printf(" %lu control messages \n", dev->ctrl_msg);
printf(" %lu unknown opcodes\n", dev->unknown);
+
+ if (dev->num_cmd_rsp)
+ printf(" Command latency: %lld-%lld msec "
+ "(~%lld msec +/- %lld msec)\n",
+ TV_MSEC(dev->cmd_latency.min),
+ TV_MSEC(dev->cmd_latency.max),
+ TV_MSEC(dev->cmd_latency.med),
+ packet_latency_stddev(&dev->cmd_latency));
+
+ /* Whatever is left never got a Command Complete or Command Status */
+ if (!queue_isempty(dev->cmd_list))
+ printf(" Commands without response: %u\n",
+ queue_length(dev->cmd_list));
+
+ queue_destroy(dev->cmd_list, free);
queue_destroy(dev->conn_list, conn_destroy);
printf("\n");
@@ -504,6 +531,7 @@ static struct hci_dev *dev_alloc(uint16_t index)
dev->manufacturer = 0xffff;
dev->conn_list = queue_new();
+ dev->cmd_list = queue_new();
return dev;
}
@@ -739,10 +767,20 @@ static void del_index(struct timeval *tv, uint16_t index,
dev_destroy(dev);
}
+static bool match_cmd_opcode(const void *data, const void *user_data)
+{
+ const struct hci_cmd *cmd = data;
+
+ return cmd->opcode == PTR_TO_UINT(user_data);
+}
+
static void command_pkt(struct timeval *tv, uint16_t index,
const void *data, uint16_t size)
{
+ const struct bt_hci_cmd_hdr *hdr = data;
struct hci_dev *dev;
+ struct hci_cmd *cmd;
+ uint16_t opcode;
dev = dev_lookup(index);
if (!dev)
@@ -750,6 +788,51 @@ static void command_pkt(struct timeval *tv, uint16_t index,
dev->num_hci++;
dev->num_cmd++;
+
+ if (size < sizeof(*hdr))
+ return;
+
+ opcode = le16_to_cpu(hdr->opcode);
+
+ /* NOP carries no request and is only used to update ncmd */
+ if (opcode == BT_HCI_CMD_NOP)
+ return;
+
+ if (queue_length(dev->cmd_list) >= CMD_LIST_MAX)
+ free(queue_pop_head(dev->cmd_list));
+
+ cmd = new0(struct hci_cmd, 1);
+ cmd->opcode = opcode;
+ cmd->tv = *tv;
+
+ queue_push_tail(dev->cmd_list, cmd);
+}
+
+/*
+ * Measure how long the controller took to acknowledge a command. Commands
+ * that are only acknowledged here and complete later through a separate
+ * event are still measured up to the acknowledgement, so that the figure
+ * stays a property of the controller rather than of the remote device.
+ */
+static void cmd_rsp(struct hci_dev *dev, struct timeval *tv, uint16_t opcode)
+{
+ struct hci_cmd *cmd;
+ struct timeval res;
+
+ /*
+ * Several commands may be outstanding at once and they need not
+ * complete in order, so match on the opcode and take the oldest.
+ */
+ cmd = queue_remove_if(dev->cmd_list, match_cmd_opcode,
+ UINT_TO_PTR(opcode));
+ if (!cmd)
+ return;
+
+ timersub(tv, &cmd->tv, &res);
+ packet_latency_add(&dev->cmd_latency, &res);
+ dev->num_cmd_rsp++;
+
+ free(cmd);
}
static void evt_conn_complete(struct hci_dev *dev, struct timeval *tv,
@@ -812,6 +895,8 @@ static void evt_cmd_complete(struct hci_dev *dev, struct timeval *tv,
opcode = le16_to_cpu(evt->opcode);
+ cmd_rsp(dev, tv, opcode);
+
switch (opcode) {
case BT_HCI_CMD_READ_BD_ADDR:
rsp_read_bd_addr(dev, tv, data, size);
@@ -819,6 +904,17 @@ static void evt_cmd_complete(struct hci_dev *dev, struct timeval *tv,
}
}
+static void evt_cmd_status(struct hci_dev *dev, struct timeval *tv,
+ const void *data, uint16_t size)
+{
+ const struct bt_hci_evt_cmd_status *evt = data;
+
+ if (size < sizeof(*evt))
+ return;
+
+ cmd_rsp(dev, tv, le16_to_cpu(evt->opcode));
+}
+
static bool match_plot_latency(const void *data, const void *user_data)
{
const struct plot *plot = data;
@@ -1114,6 +1210,9 @@ static void event_pkt(struct timeval *tv, uint16_t index,
case BT_HCI_EVT_CMD_COMPLETE:
evt_cmd_complete(dev, tv, data, size);
break;
+ case BT_HCI_EVT_CMD_STATUS:
+ evt_cmd_status(dev, tv, data, size);
+ break;
case BT_HCI_EVT_NUM_COMPLETED_PACKETS:
evt_num_completed_packets(dev, tv, data, size);
break;
--
2.55.0
^ permalink raw reply related [flat|nested] 12+ messages in thread* [PATCH BlueZ v1 06/10] doc/btmon: Document the command latency statistics
2026-09-09 18:28 [PATCH BlueZ v1 00/10] monitor: Reference request frames on responses Luiz Augusto von Dentz
` (4 preceding siblings ...)
2026-09-09 18:28 ` [PATCH BlueZ v1 05/10] monitor: Report command latency in analyze mode Luiz Augusto von Dentz
@ 2026-09-09 18:28 ` Luiz Augusto von Dentz
2026-09-09 18:28 ` [PATCH BlueZ v1 07/10] monitor: Add request tracking for the protocols above HCI Luiz Augusto von Dentz
` (3 subsequent siblings)
9 siblings, 0 replies; 12+ messages in thread
From: Luiz Augusto von Dentz @ 2026-09-09 18:28 UTC (permalink / raw)
To: linux-bluetooth
From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
Describe what the command latency measures, why deferred commands are
only measured up to their acknowledgement, and how to read the count of
commands without a response.
The model drafted the text, which the author reviewed against the actual
output.
Assisted-by: opencode:claude-opus-5
---
doc/btmon.rst | 27 +++++++++++++++++++++++++++
1 file changed, 27 insertions(+)
diff --git a/doc/btmon.rst b/doc/btmon.rst
index c8611ab2e9e7..80c8a8947caf 100644
--- a/doc/btmon.rst
+++ b/doc/btmon.rst
@@ -591,6 +591,9 @@ Analyze mode reports, for each controller found in the trace:
events, ACL, SCO, ISO, vendor diagnostics, system notes, user
logs, control messages).
+- **Command latency**: How long the controller took to acknowledge
+ commands, and how many commands were never answered at all.
+
- **Per-connection statistics**: For each connection handle found:
- Connection type (BR-ACL, LE-ACL, BR-SCO, BR-ESCO, LE-ISO)
@@ -627,6 +630,30 @@ interference, retransmissions or controller buffer stalls. Comparing the
maximum against ``average + deviation`` shows whether the worst case is
representative or a one-off outlier.
+Command Latency
+---------------
+
+Command latency is reported per controller::
+
+ Command latency: 0-215 msec (~55 msec +/- 70 msec)
+ Commands without response: 3
+
+This measures the interval between an HCI command and the ``Command
+Complete`` or ``Command Status`` that acknowledges it, so it describes the
+responsiveness of the controller itself.
+
+Commands that are only acknowledged by a ``Command Status`` and complete
+much later through a separate event are measured up to the acknowledgement
+only. A ``Create Connection`` that takes three seconds to reach its
+``Connect Complete`` is waiting on the remote device rather than on the
+controller, and including it would swamp both the average and the
+deviation.
+
+``Commands without response`` counts commands that were never acknowledged
+at all before the end of the trace. A non-zero value usually means the
+capture simply ended with commands in flight, but a persistently high count
+points at firmware dropping commands.
+
Packet Loss
-----------
--
2.55.0
^ permalink raw reply related [flat|nested] 12+ messages in thread* [PATCH BlueZ v1 07/10] monitor: Add request tracking for the protocols above HCI
2026-09-09 18:28 [PATCH BlueZ v1 00/10] monitor: Reference request frames on responses Luiz Augusto von Dentz
` (5 preceding siblings ...)
2026-09-09 18:28 ` [PATCH BlueZ v1 06/10] doc/btmon: Document the command latency statistics Luiz Augusto von Dentz
@ 2026-09-09 18:28 ` Luiz Augusto von Dentz
2026-09-09 18:28 ` [PATCH BlueZ v1 08/10] monitor/att: Reference the request frame on responses Luiz Augusto von Dentz
` (2 subsequent siblings)
9 siblings, 0 replies; 12+ messages in thread
From: Luiz Augusto von Dentz @ 2026-09-09 18:28 UTC (permalink / raw)
To: linux-bluetooth
From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
The protocols carried over ACL pair their requests and responses through
an identifier of their own, but a response gives no hint of where its
request was, and the time between the two is only visible by comparing
timestamps by hand.
Track outstanding requests per connection so that a response can name the
frame that carried the request, and use it for L2CAP signalling, where
responses are the request code plus one and a Command Reject may answer
any request:
L2CAP: Connection Request (0x02) ident 1 len 4
L2CAP: Connection Response (0x03) ident 1 len 8 #2 (1.000 msec)
None of these layers had access to a timestamp or a frame number, since
neither is passed down from the HCI decoding. Rather than thread both
through every protocol handler, record the packet being decoded and pick
it up in l2cap_frame_init(), which every frame passes through.
Requests are keyed on the channel rather than on the CID, because a CID
names the receiving end and therefore differs between the two directions
of the same channel. Fixed channels keep using the CID, which is already
the same either way.
The model wrote the tracking, which the author reviewed and verified
against traces covering matched and unmatched responses on both fixed and
dynamically allocated channels.
Assisted-by: opencode:claude-opus-5
---
monitor/l2cap.c | 76 ++++++++++++++++++++++++++---
monitor/l2cap.h | 8 +++
monitor/packet.c | 124 +++++++++++++++++++++++++++++++++++++++++++++++
monitor/packet.h | 14 ++++++
4 files changed, 214 insertions(+), 8 deletions(-)
diff --git a/monitor/l2cap.c b/monitor/l2cap.c
index e9a1df824e57..a132bcf397f4 100644
--- a/monitor/l2cap.c
+++ b/monitor/l2cap.c
@@ -283,6 +283,30 @@ static int get_chan_data_index(const struct l2cap_frame *frame)
return -1;
}
+/*
+ * Channel identifier for request and response matching. L2CAP CIDs are
+ * direction specific, so a dynamic channel is identified by its entry,
+ * which is the same for both directions. Fixed channels have no entry and
+ * use the CID, which is already direction independent.
+ */
+uint16_t l2cap_chan_key(uint16_t index, bool in, uint16_t handle, uint16_t cid)
+{
+ struct l2cap_frame frame;
+ int i;
+
+ memset(&frame, 0, sizeof(frame));
+ frame.index = index;
+ frame.in = in;
+ frame.handle = handle;
+ frame.cid = cid;
+
+ i = get_chan_data_index(&frame);
+ if (i >= 0)
+ return 0x8000 | i;
+
+ return cid;
+}
+
static struct chan_data *get_chan(const struct l2cap_frame *frame)
{
int i;
@@ -1578,6 +1602,32 @@ static const struct sig_opcode_data le_sig_opcode_table[] = {
{ },
};
+/*
+ * L2CAP signalling responses use the request code plus one, and a Command
+ * Reject may answer any request. Requests are tracked per identifier, which
+ * is what pairs the two halves of a signalling transaction.
+ */
+static void sig_req_str(const struct l2cap_frame *frame, uint8_t code,
+ char *str, size_t len)
+{
+ uint16_t key;
+
+ str[0] = '\0';
+
+ key = l2cap_chan_key(frame->index, frame->in, frame->handle,
+ frame->cid);
+
+ if (code == BT_L2CAP_PDU_CMD_REJECT || (code & 0x01)) {
+ packet_req_str(frame->handle, key, PACKET_PROTO_L2CAP,
+ frame->ident, (struct timeval *)&frame->tv,
+ str, len);
+ return;
+ }
+
+ packet_req_add(frame->handle, key, PACKET_PROTO_L2CAP, frame->ident,
+ (struct timeval *)&frame->tv, frame->num);
+}
+
static void l2cap_queue_frame(struct l2cap_frame *frame)
{
struct packet_conn_data *conn;
@@ -1612,6 +1662,8 @@ void l2cap_frame_init(struct l2cap_frame *frame, uint16_t index, bool in,
frame->mode = get_mode(frame);
frame->seq_num = psm ? 1 : get_seq_num(frame);
+ packet_get_context(&frame->tv, &frame->num);
+
if (!in)
l2cap_queue_frame(frame);
}
@@ -1620,6 +1672,7 @@ static void bredr_sig_packet(uint16_t index, bool in, uint16_t handle,
uint16_t cid, const void *data, uint16_t size)
{
struct l2cap_frame frame;
+ char req_str[32];
while (size > 0) {
const struct bt_l2cap_hdr_sig *hdr = data;
@@ -1666,10 +1719,15 @@ static void bredr_sig_packet(uint16_t index, bool in, uint16_t handle,
opcode_str = "Unknown";
}
+ l2cap_frame_init(&frame, index, in, handle, hdr->ident, cid,
+ 0, data, len);
+ sig_req_str(&frame, hdr->code, req_str, sizeof(req_str));
+
print_indent(6, opcode_color, "L2CAP: ", opcode_str,
COLOR_OFF,
- " (0x%2.2x) ident %d len %d",
- hdr->code, hdr->ident, len);
+ " (0x%2.2x) ident %d len %d%s%s",
+ hdr->code, hdr->ident, len,
+ req_str[0] ? " " : "", req_str);
if (!opcode_data || !opcode_data->func) {
packet_hexdump(data, len);
@@ -1696,8 +1754,6 @@ static void bredr_sig_packet(uint16_t index, bool in, uint16_t handle,
}
}
- l2cap_frame_init(&frame, index, in, handle, hdr->ident, cid, 0,
- data, len);
opcode_data->func(&frame);
data += len;
@@ -1711,6 +1767,7 @@ static void le_sig_packet(uint16_t index, bool in, uint16_t handle,
uint16_t cid, const void *data, uint16_t size)
{
struct l2cap_frame frame;
+ char req_str[32];
const struct bt_l2cap_hdr_sig *hdr = data;
const struct sig_opcode_data *opcode_data = NULL;
const char *opcode_color, *opcode_str;
@@ -1755,9 +1812,14 @@ static void le_sig_packet(uint16_t index, bool in, uint16_t handle,
opcode_str = "Unknown";
}
+ l2cap_frame_init(&frame, index, in, handle, hdr->ident, cid, 0,
+ data, len);
+ sig_req_str(&frame, hdr->code, req_str, sizeof(req_str));
+
print_indent(6, opcode_color, "LE L2CAP: ", opcode_str, COLOR_OFF,
- " (0x%2.2x) ident %d len %d",
- hdr->code, hdr->ident, len);
+ " (0x%2.2x) ident %d len %d%s%s",
+ hdr->code, hdr->ident, len,
+ req_str[0] ? " " : "", req_str);
if (!opcode_data || !opcode_data->func) {
packet_hexdump(data, len);
@@ -1778,8 +1840,6 @@ static void le_sig_packet(uint16_t index, bool in, uint16_t handle,
}
}
- l2cap_frame_init(&frame, index, in, handle, hdr->ident, cid, 0,
- data, len);
opcode_data->func(&frame);
}
diff --git a/monitor/l2cap.h b/monitor/l2cap.h
index b545bf686c05..1c1f7e609cb4 100644
--- a/monitor/l2cap.h
+++ b/monitor/l2cap.h
@@ -11,6 +11,7 @@
#include <stdint.h>
#include <stdbool.h>
+#include <sys/time.h>
struct l2cap_frame {
uint16_t index;
@@ -24,6 +25,8 @@ struct l2cap_frame {
uint8_t seq_num;
const void *data;
uint16_t size;
+ struct timeval tv; /* Timestamp of the carrying frame */
+ size_t num; /* Number of the carrying frame */
};
void l2cap_frame_init(struct l2cap_frame *frame, uint16_t index, bool in,
@@ -46,6 +49,8 @@ static inline void l2cap_frame_clone_size(struct l2cap_frame *frame,
frame->mode = source->mode;
frame->data = source->data;
frame->size = size;
+ frame->tv = source->tv;
+ frame->num = source->num;
}
}
@@ -351,6 +356,9 @@ static inline bool l2cap_frame_get_be128(struct l2cap_frame *frame,
void l2cap_frame(uint16_t index, bool in, uint16_t handle, uint16_t cid,
uint16_t psm, const void *data, uint16_t size);
+uint16_t l2cap_chan_key(uint16_t index, bool in, uint16_t handle,
+ uint16_t cid);
+
void l2cap_packet(uint16_t index, bool in, uint16_t handle, uint8_t flags,
const void *data, uint16_t size);
diff --git a/monitor/packet.c b/monitor/packet.c
index 053c1165bf99..e8990f12b385 100644
--- a/monitor/packet.c
+++ b/monitor/packet.c
@@ -554,6 +554,7 @@ static struct packet_conn_data *release_handle(uint16_t handle)
queue_destroy(conn->tx_q, free);
queue_destroy(conn->chan_q, free);
+ queue_destroy(conn->req_q, free);
memset(conn, 0, sizeof(*conn));
conn->handle = 0xffff;
return conn;
@@ -11913,6 +11914,125 @@ void packet_loss_add(struct packet_loss *loss, uint16_t sn, uint8_t sflags)
loss->have_sn = true;
}
+/*
+ * Timestamp and frame number of the packet being decoded. btmon decodes one
+ * packet at a time, so this lets the upper layers reference the frame that
+ * carried a request without threading it through every protocol handler.
+ */
+static struct timeval cur_tv;
+static bool cur_tv_valid;
+static size_t cur_num;
+
+static void packet_set_context(struct timeval *tv, size_t num)
+{
+ cur_tv_valid = tv;
+ if (tv)
+ cur_tv = *tv;
+ cur_num = num;
+}
+
+void packet_get_context(struct timeval *tv, size_t *num)
+{
+ if (tv) {
+ if (cur_tv_valid)
+ *tv = cur_tv;
+ else
+ timerclear(tv);
+ }
+
+ if (num)
+ *num = cur_num;
+}
+
+/*
+ * Requests from the protocols above HCI, so that a response can point back
+ * at the frame that carried the request.
+ */
+struct packet_req {
+ uint16_t cid;
+ uint8_t proto;
+ uint16_t id;
+ size_t num;
+ struct timeval tv;
+};
+
+/* Bound the queue so requests that never get a response cannot pile up */
+#define PACKET_REQ_MAX 64
+
+static bool match_packet_req(const void *data, const void *user_data)
+{
+ const struct packet_req *req = data;
+ const struct packet_req *match = user_data;
+
+ return req->cid == match->cid && req->proto == match->proto &&
+ req->id == match->id;
+}
+
+void packet_req_add(uint16_t handle, uint16_t cid, uint8_t proto, uint16_t id,
+ struct timeval *tv, size_t num)
+{
+ struct packet_conn_data *conn;
+ struct packet_req *req;
+
+ conn = packet_get_conn_data(handle);
+ if (!conn)
+ return;
+
+ if (!conn->req_q)
+ conn->req_q = queue_new();
+
+ if (queue_length(conn->req_q) >= PACKET_REQ_MAX)
+ free(queue_pop_head(conn->req_q));
+
+ req = new0(struct packet_req, 1);
+ req->cid = cid;
+ req->proto = proto;
+ req->id = id;
+ req->num = num;
+ if (tv)
+ req->tv = *tv;
+
+ queue_push_tail(conn->req_q, req);
+}
+
+/*
+ * Format the request reference for a response. Leaves the string empty when
+ * the request was not seen, which is the normal case for a capture started
+ * while a transaction was already in progress.
+ */
+void packet_req_str(uint16_t handle, uint16_t cid, uint8_t proto, uint16_t id,
+ struct timeval *tv, char *str, size_t len)
+{
+ struct packet_conn_data *conn;
+ struct packet_req *req, match;
+ struct timeval delta;
+
+ str[0] = '\0';
+
+ conn = packet_get_conn_data(handle);
+ if (!conn)
+ return;
+
+ match.cid = cid;
+ match.proto = proto;
+ match.id = id;
+
+ req = queue_remove_if(conn->req_q, match_packet_req, &match);
+ if (!req)
+ return;
+
+ if (tv && timerisset(tv) && timerisset(&req->tv)) {
+ timersub(tv, &req->tv, &delta);
+ snprintf(str, len, "#%zu (%lld.%03lld msec)", req->num,
+ (long long)delta.tv_sec * 1000 +
+ delta.tv_usec / 1000,
+ (long long)delta.tv_usec % 1000);
+ } else
+ snprintf(str, len, "#%zu", req->num);
+
+ free(req);
+}
+
static void packet_dequeue_tx(struct timeval *tv, uint16_t handle)
{
struct packet_conn_data *conn;
@@ -14866,7 +14986,11 @@ void packet_hci_acldata(struct timeval *tv, struct ucred *cred, uint16_t index,
if (filter_mask & PACKET_FILTER_SHOW_ACL_DATA)
packet_hexdump(data, size);
+ packet_set_context(tv, index_list[index].frame);
+
l2cap_packet(index, in, acl_handle(handle), flags, data, size);
+
+ packet_set_context(NULL, 0);
}
void packet_hci_scodata(struct timeval *tv, struct ucred *cred, uint16_t index,
diff --git a/monitor/packet.h b/monitor/packet.h
index 9d1efdf45258..dc6e6c6a7a57 100644
--- a/monitor/packet.h
+++ b/monitor/packet.h
@@ -45,6 +45,13 @@ struct packet_loss {
size_t total; /* Samples seen, including the lost ones */
};
+/* Protocols tracked for request and response matching */
+#define PACKET_PROTO_L2CAP 0x00
+#define PACKET_PROTO_ATT 0x01
+#define PACKET_PROTO_SDP 0x02
+#define PACKET_PROTO_AVDTP 0x03
+#define PACKET_PROTO_AVCTP 0x04
+
struct packet_frame {
struct timeval tv;
size_t num;
@@ -76,6 +83,7 @@ struct packet_conn_data {
struct queue *chan_q;
struct packet_latency tx_l;
struct packet_loss rx_loss;
+ struct queue *req_q;
void *data;
void (*destroy)(struct packet_conn_data *conn, void *data);
};
@@ -85,6 +93,12 @@ void packet_latency_add(struct packet_latency *latency, struct timeval *delta);
long long packet_latency_stddev(const struct packet_latency *latency);
void packet_loss_add(struct packet_loss *loss, uint16_t sn, uint8_t sflags);
+void packet_get_context(struct timeval *tv, size_t *num);
+void packet_req_add(uint16_t handle, uint16_t cid, uint8_t proto, uint16_t id,
+ struct timeval *tv, size_t num);
+void packet_req_str(uint16_t handle, uint16_t cid, uint8_t proto, uint16_t id,
+ struct timeval *tv, char *str, size_t len);
+
bool packet_has_filter(unsigned long filter);
void packet_set_filter(unsigned long filter);
void packet_add_filter(unsigned long filter);
--
2.55.0
^ permalink raw reply related [flat|nested] 12+ messages in thread* [PATCH BlueZ v1 08/10] monitor/att: Reference the request frame on responses
2026-09-09 18:28 [PATCH BlueZ v1 00/10] monitor: Reference request frames on responses Luiz Augusto von Dentz
` (6 preceding siblings ...)
2026-09-09 18:28 ` [PATCH BlueZ v1 07/10] monitor: Add request tracking for the protocols above HCI Luiz Augusto von Dentz
@ 2026-09-09 18:28 ` Luiz Augusto von Dentz
2026-09-09 18:28 ` [PATCH BlueZ v1 09/10] monitor: Reference the request frame on SDP, AVDTP and AVCTP responses Luiz Augusto von Dentz
2026-09-09 18:28 ` [PATCH BlueZ v1 10/10] doc/btmon: Document the protocol request references Luiz Augusto von Dentz
9 siblings, 0 replies; 12+ messages in thread
From: Luiz Augusto von Dentz @ 2026-09-09 18:28 UTC (permalink / raw)
To: linux-bluetooth
From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
ATT responses use the request opcode plus one, and only one request may be
outstanding on a bearer, so the opcode itself identifies the transaction:
ATT: Read By Group Type Request (0x10) len 6
ATT: Error Response (0x01) len 4 #6 (45.500 msec)
An Error Response names the request it rejects rather than following the
plus one rule, so it is matched on the opcode it carries. A Handle Value
Indication is paired with the confirmation that answers it.
The model wrote the matching, which the author reviewed and verified
against a trace covering ordinary responses, an Error Response, an
indication and a response with no request.
Assisted-by: opencode:claude-opus-5
---
monitor/att.c | 69 ++++++++++++++++++++++++++++++++++++++++++++++++++-
1 file changed, 68 insertions(+), 1 deletion(-)
diff --git a/monitor/att.c b/monitor/att.c
index 44965a2aaf3b..a35198949e3d 100644
--- a/monitor/att.c
+++ b/monitor/att.c
@@ -5873,6 +5873,64 @@ static const char *att_opcode_to_str(uint8_t opcode)
return "Unknown";
}
+/*
+ * ATT responses use the request opcode plus one, except for an Error
+ * Response which names the request it rejects. Only one request may be
+ * outstanding on a bearer, so the opcode itself identifies the transaction.
+ */
+static void att_req_str(uint16_t handle, uint16_t key, uint8_t opcode,
+ const void *data, uint16_t size, struct timeval *tv,
+ size_t num, char *str, size_t len)
+{
+ str[0] = '\0';
+
+ switch (opcode) {
+ /* Requests, and the indication which is answered by a confirmation */
+ case 0x02:
+ case 0x04:
+ case 0x06:
+ case 0x08:
+ case 0x0a:
+ case 0x0c:
+ case 0x0e:
+ case 0x10:
+ case 0x12:
+ case 0x16:
+ case 0x18:
+ case 0x1d:
+ case 0x20:
+ packet_req_add(handle, key, PACKET_PROTO_ATT, opcode, tv,
+ num);
+ return;
+ case 0x01:
+ /* The rejected request is named in the response */
+ if (size < 1)
+ return;
+ packet_req_str(handle, key, PACKET_PROTO_ATT,
+ *((const uint8_t *) data), tv, str, len);
+ return;
+ case 0x1e:
+ packet_req_str(handle, key, PACKET_PROTO_ATT, 0x1d, tv, str,
+ len);
+ return;
+ case 0x03:
+ case 0x05:
+ case 0x07:
+ case 0x09:
+ case 0x0b:
+ case 0x0d:
+ case 0x0f:
+ case 0x11:
+ case 0x13:
+ case 0x17:
+ case 0x19:
+ case 0x21:
+ packet_req_str(handle, key, PACKET_PROTO_ATT, opcode - 1, tv,
+ str, len);
+ return;
+ }
+}
+
void att_packet(uint16_t index, bool in, uint16_t handle, uint16_t cid,
const void *data, uint16_t size)
{
@@ -5880,6 +5938,9 @@ void att_packet(uint16_t index, bool in, uint16_t handle, uint16_t cid,
uint8_t opcode = *((const uint8_t *) data);
const struct att_opcode_data *opcode_data = NULL;
const char *opcode_color, *opcode_str;
+ char req_str[32];
+ struct timeval tv;
+ size_t num;
int i;
if (size < 1) {
@@ -5909,8 +5970,14 @@ void att_packet(uint16_t index, bool in, uint16_t handle, uint16_t cid,
opcode_str = "Unknown";
}
+ packet_get_context(&tv, &num);
+ att_req_str(handle, l2cap_chan_key(index, in, handle, cid), opcode,
+ data + 1, size - 1, &tv, num, req_str,
+ sizeof(req_str));
+
print_indent(6, opcode_color, "ATT: ", opcode_str, COLOR_OFF,
- " (0x%2.2x) len %d", opcode, size - 1);
+ " (0x%2.2x) len %d%s%s", opcode, size - 1,
+ req_str[0] ? " " : "", req_str);
if (!opcode_data || !opcode_data->func) {
packet_hexdump(data + 1, size - 1);
--
2.55.0
^ permalink raw reply related [flat|nested] 12+ messages in thread* [PATCH BlueZ v1 09/10] monitor: Reference the request frame on SDP, AVDTP and AVCTP responses
2026-09-09 18:28 [PATCH BlueZ v1 00/10] monitor: Reference request frames on responses Luiz Augusto von Dentz
` (7 preceding siblings ...)
2026-09-09 18:28 ` [PATCH BlueZ v1 08/10] monitor/att: Reference the request frame on responses Luiz Augusto von Dentz
@ 2026-09-09 18:28 ` Luiz Augusto von Dentz
2026-09-09 18:28 ` [PATCH BlueZ v1 10/10] doc/btmon: Document the protocol request references Luiz Augusto von Dentz
9 siblings, 0 replies; 12+ messages in thread
From: Luiz Augusto von Dentz @ 2026-09-09 18:28 UTC (permalink / raw)
To: linux-bluetooth
From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
SDP pairs a request with its response through the transaction identifier,
and responses use the request PDU plus one with an Error Response able to
answer any request. AVDTP and AVCTP both pair a command with its response
through the transaction label:
SDP: Service Search Request (0x02) tid 5 len 8
SDP: Service Search Response (0x03) tid 5 len 5 #8 (12.400 msec)
AVCTP Control: Command: type 0x00 label 7 PID 0x110e
AVCTP Control: Response: type 0x00 label 7 PID 0x110e #12 (23.100 msec)
These all run on dynamically allocated channels, which is what the channel
keyed matching was needed for.
The model wrote the matching, which the author reviewed and verified
against a trace carrying all three over separate channels.
Assisted-by: opencode:claude-opus-5
---
monitor/avctp.c | 24 ++++++++++++++++++++++--
monitor/avdtp.c | 24 ++++++++++++++++++++++--
monitor/sdp.c | 21 ++++++++++++++++++++-
3 files changed, 64 insertions(+), 5 deletions(-)
diff --git a/monitor/avctp.c b/monitor/avctp.c
index 0db352f18ffd..75afaca8342f 100644
--- a/monitor/avctp.c
+++ b/monitor/avctp.c
@@ -2512,6 +2512,8 @@ void avctp_packet(const struct l2cap_frame *frame)
struct l2cap_frame *l2cap_frame;
struct avctp_frame avctp_frame;
const char *pdu_color;
+ char req_str[32];
+ uint16_t key;
l2cap_frame_pull(&avctp_frame.l2cap_frame, frame, 0);
@@ -2529,12 +2531,30 @@ void avctp_packet(const struct l2cap_frame *frame)
else
pdu_color = COLOR_BLUE;
+ /*
+ * A command is answered by a response carrying the same transaction
+ * label, which is what pairs the two.
+ */
+ key = l2cap_chan_key(frame->index, frame->in, frame->handle,
+ frame->cid);
+ req_str[0] = '\0';
+ if (avctp_frame.hdr & 0x02)
+ packet_req_str(frame->handle, key, PACKET_PROTO_AVCTP,
+ avctp_frame.hdr >> 4,
+ (struct timeval *)&frame->tv,
+ req_str, sizeof(req_str));
+ else
+ packet_req_add(frame->handle, key, PACKET_PROTO_AVCTP,
+ avctp_frame.hdr >> 4,
+ (struct timeval *)&frame->tv, frame->num);
+
print_indent(6, pdu_color, "AVCTP", "", COLOR_OFF,
- " %s: %s: type 0x%02x label %d PID 0x%04x",
+ " %s: %s: type 0x%02x label %d PID 0x%04x%s%s",
frame->psm == 23 ? "Control" : "Browsing",
avctp_frame.hdr & 0x02 ? "Response" : "Command",
avctp_frame.hdr & 0x0c, avctp_frame.hdr >> 4,
- avctp_frame.pid);
+ avctp_frame.pid,
+ req_str[0] ? " " : "", req_str);
if (avctp_frame.pid == 0x110e || avctp_frame.pid == 0x110c)
avrcp_packet(&avctp_frame);
diff --git a/monitor/avdtp.c b/monitor/avdtp.c
index d1eb15356602..9d0016d6bc56 100644
--- a/monitor/avdtp.c
+++ b/monitor/avdtp.c
@@ -667,6 +667,8 @@ static bool avdtp_delayreport(struct avdtp_frame *avdtp_frame)
static bool avdtp_signalling_packet(struct avdtp_frame *avdtp_frame)
{
+ char req_str[32];
+ uint16_t key;
struct l2cap_frame *frame = &avdtp_frame->l2cap_frame;
const char *pdu_color;
uint8_t hdr;
@@ -703,10 +705,28 @@ static bool avdtp_signalling_packet(struct avdtp_frame *avdtp_frame)
avdtp_frame->sig_id = sig_id;
+ /*
+ * A command is answered by a response accept or reject carrying the
+ * same transaction label, which is what pairs the two.
+ */
+ key = l2cap_chan_key(frame->index, frame->in, frame->handle,
+ frame->cid);
+ req_str[0] = '\0';
+ if ((hdr & 0x03) == 0x00)
+ packet_req_add(frame->handle, key, PACKET_PROTO_AVDTP,
+ hdr >> 4, (struct timeval *)&frame->tv,
+ frame->num);
+ else
+ packet_req_str(frame->handle, key, PACKET_PROTO_AVDTP,
+ hdr >> 4, (struct timeval *)&frame->tv,
+ req_str, sizeof(req_str));
+
print_indent(6, pdu_color, "AVDTP: ", sigid2str(sig_id), COLOR_OFF,
- " (0x%02x) %s (0x%02x) type 0x%02x label %d nosp %d",
+ " (0x%02x) %s (0x%02x) type 0x%02x label %d nosp %d"
+ "%s%s",
sig_id, msgtype2str(hdr & 0x03), hdr & 0x03,
- hdr & 0x0c, hdr >> 4, nosp);
+ hdr & 0x0c, hdr >> 4, nosp,
+ req_str[0] ? " " : "", req_str);
/* Start Packet */
if ((hdr & 0x0c) == 0x04) {
diff --git a/monitor/sdp.c b/monitor/sdp.c
index 9f97ba4bbea0..ce06b73ec59f 100644
--- a/monitor/sdp.c
+++ b/monitor/sdp.c
@@ -713,6 +713,8 @@ static const struct sdp_data sdp_table[] = {
void sdp_packet(const struct l2cap_frame *frame)
{
+ char req_str[32];
+ uint16_t key;
uint8_t pdu;
uint16_t tid, plen;
struct l2cap_frame sdp_frame;
@@ -758,8 +760,25 @@ void sdp_packet(const struct l2cap_frame *frame)
pdu_str = "Unknown";
}
+ /*
+ * SDP responses use the request PDU plus one, and an Error Response
+ * may answer any request. The transaction identifier pairs them.
+ */
+ key = l2cap_chan_key(frame->index, frame->in, frame->handle,
+ frame->cid);
+ req_str[0] = '\0';
+ if (pdu == 0x02 || pdu == 0x04 || pdu == 0x06)
+ packet_req_add(frame->handle, key, PACKET_PROTO_SDP,
+ tid, (struct timeval *)&frame->tv,
+ frame->num);
+ else if (pdu == 0x01 || pdu == 0x03 || pdu == 0x05 || pdu == 0x07)
+ packet_req_str(frame->handle, key, PACKET_PROTO_SDP,
+ tid, (struct timeval *)&frame->tv,
+ req_str, sizeof(req_str));
+
print_indent(6, pdu_color, "SDP: ", pdu_str, COLOR_OFF,
- " (0x%2.2x) tid %d len %d", pdu, tid, plen);
+ " (0x%2.2x) tid %d len %d%s%s", pdu, tid, plen,
+ req_str[0] ? " " : "", req_str);
tid_info = get_tid(tid, frame->chan);
--
2.55.0
^ permalink raw reply related [flat|nested] 12+ messages in thread* [PATCH BlueZ v1 10/10] doc/btmon: Document the protocol request references
2026-09-09 18:28 [PATCH BlueZ v1 00/10] monitor: Reference request frames on responses Luiz Augusto von Dentz
` (8 preceding siblings ...)
2026-09-09 18:28 ` [PATCH BlueZ v1 09/10] monitor: Reference the request frame on SDP, AVDTP and AVCTP responses Luiz Augusto von Dentz
@ 2026-09-09 18:28 ` Luiz Augusto von Dentz
9 siblings, 0 replies; 12+ messages in thread
From: Luiz Augusto von Dentz @ 2026-09-09 18:28 UTC (permalink / raw)
To: linux-bluetooth
From: Luiz Augusto von Dentz <luiz.von.dentz@intel.com>
Describe the request references shown on L2CAP, ATT, SDP, AVDTP and AVCTP
responses, and what pairs the two halves of a transaction in each of them.
The model drafted the text, which the author reviewed against the actual
output.
Assisted-by: opencode:claude-opus-5
---
doc/btmon.rst | 47 +++++++++++++++++++++++++++++++++++++++++++++++
1 file changed, 47 insertions(+)
diff --git a/doc/btmon.rst b/doc/btmon.rst
index 80c8a8947caf..a08a6afa43f4 100644
--- a/doc/btmon.rst
+++ b/doc/btmon.rst
@@ -275,6 +275,53 @@ once and still resolve correctly. A ``Command Status`` reporting an error
means the completing event will never arrive, and the command is dropped
rather than left to match a later unrelated event.
+Protocols Above HCI
+-------------------
+
+The protocols carried over ACL pair their requests and responses through an
+identifier of their own, and their responses carry the same reference::
+
+ L2CAP: Connection Request (0x02) ident 1 len 4
+ L2CAP: Connection Response (0x03) ident 1 len 8 #2 (1.000 msec)
+ ATT: Read By Group Type Request (0x10) len 6
+ ATT: Error Response (0x01) len 4 #6 (45.500 msec)
+ SDP: Service Search Request (0x02) tid 5 len 8
+ SDP: Service Search Response (0x03) tid 5 len 5 #8 (12.400 msec)
+ AVCTP Control: Command: type 0x00 label 7 PID 0x110e
+ AVCTP Control: Response: type 0x00 label 7 PID 0x110e #12 (23.100 msec)
+
+What pairs the two halves differs by protocol:
+
+.. list-table::
+ :header-rows: 1
+ :widths: 15 20 65
+
+ * - Protocol
+ - Paired by
+ - Notes
+ * - L2CAP
+ - ``ident``
+ - Responses are the request code plus one. A Command Reject
+ may answer any request.
+ * - ATT
+ - Opcode
+ - Responses are the request opcode plus one. Only one request
+ may be outstanding on a bearer. An Error Response names the
+ request it rejects. An indication is paired with its
+ confirmation.
+ * - SDP
+ - ``tid``
+ - Responses are the request PDU plus one. An Error Response
+ may answer any request.
+ * - AVDTP
+ - ``label``
+ - A command is answered by a response accept or reject.
+ * - AVCTP
+ - ``label``
+ - A command is answered by a response.
+
+SMP is not tracked, as its exchange has no transaction identifier.
+
**LE Meta Events** contain a subevent type::
> HCI Event: LE Meta Event (0x3e) plen 31 #487 [hci0] 12:36:18.974201
--
2.55.0
^ permalink raw reply related [flat|nested] 12+ messages in thread