Decoding Bluetooth Communication: A Comprehensive Guide to Reading btmon Log Files #

At revWhiteShadow, we understand the critical need for precise analysis of Bluetooth communications. When monitoring the intricate dance of packets sent and received by peer devices, the btmon utility on Ubuntu provides an invaluable, albeit sometimes cryptic, window into this world. This guide is meticulously crafted to demystify the btmon log format, enabling you to accurately identify sent and received packets, understand the flow of data, and precisely determine the latency between a peer device sending a packet and its reception. We will delve deep into the log structure, leveraging our expertise to help you outrank existing resources by providing unparalleled detail and clarity.

Understanding the Core of btmon Logging #

The btmon command, when executed, captures raw Bluetooth traffic from your system’s Bluetooth adapter. This traffic is presented in a human-readable format, but interpreting it requires a foundational understanding of the underlying Bluetooth protocols and how btmon represents them. The logs you encounter are timestamped, indicating the precise moment an event occurred, and are typically associated with a specific Bluetooth controller (e.g., [hci0]). The most crucial elements for distinguishing sent and received data are the directional indicators and the packet types.

Directional Indicators: The Key to Packet Flow #

The most immediate clue in btmon logs for understanding packet direction is the presence of prefix symbols before each log entry. These symbols are not arbitrary; they convey vital information about the origin and destination of the observed Bluetooth event.

< Symbol: Indicating Transmitted Data #

When you observe a log entry prefixed with a < symbol, it signifies that the event being logged is related to data being transmitted from your system (the one running btmon) to a peer device. This could be a command, a data packet, or any other form of information being sent out. The following text, such as ACL Data TX or HCI Command, further specifies the nature of this outgoing transmission.

> Symbol: Signifying Received Data #

Conversely, a log entry starting with a > symbol indicates that the event is related to data being received by your system from a peer device. This could be a response to a sent command, a data notification, or any inbound Bluetooth traffic. Again, the subsequent descriptive text, like ACL Data RX or HCI Event, provides context to this incoming data.

Timestamp Granularity: Pinpointing Event Timing #

Each line in a btmon log file is accompanied by a timestamp, typically displayed in seconds with high precision (e.g., 20.084811). This timestamp is crucial for analyzing the timing of events.

• Transmission Timestamp: When you see a < ACL Data TX: or < HCI Command: entry, the timestamp associated with it represents the moment your system initiated the transmission of that specific packet or command.
• Reception Timestamp: When you encounter a > ACL Data RX: or > HCI Event: entry, the timestamp marks the exact moment your system received that particular packet or event.

By comparing these timestamps for corresponding sent and received packets, we can accurately calculate the round-trip time or the time taken by the peer device to respond after receiving a transmission.

Deconstructing Packet Types and Layers #

Beyond the directional indicators, the content of the log entries provides a deeper understanding of the Bluetooth communication stack. btmon often logs at different levels of the Bluetooth protocol, from the low-level HCI (Host Controller Interface) to higher-level protocols like L2CAP and ATT (Attribute Protocol).

HCI (Host Controller Interface) Layer #

The HCI layer is the interface between the host (your Ubuntu system’s Bluetooth stack) and the controller (the physical Bluetooth hardware). btmon logs from this layer are fundamental to understanding the basic communication flow.

HCI Commands (< HCI Command:) #

These entries represent commands sent from the host to the controller to perform specific actions, such as initiating a connection, sending data, or querying controller status. The HCI Command entries are typically followed by a command code and parameters.

HCI Events (> HCI Event:) #

These are asynchronous events reported by the controller to the host. They can signal the completion of a command, the arrival of data, or various status changes. The Number of Completed Packets event, for instance, is a crucial acknowledgment mechanism.

• Number of Completed Packets (0x13): This event is frequently observed after a transmission. It indicates that the Bluetooth controller has finished processing and transmitting a certain number of packets that were previously queued. The Handle and Count fields within this event are important for correlating the acknowledgment with the original transmission.

ACL (Asynchronous Connection-Less) Data Layer #

ACL data is used for transporting user data and signaling information between Bluetooth devices once a connection has been established. These are the packets that carry the actual payload of your Bluetooth communication.

ACL Data TX: (< ACL Data TX:) #

This signifies that ACL data is being transmitted from your system. The Handle refers to a specific connection or link identifier, and dlen indicates the data length. The flags field provides further context about the packet’s segmentation and reassembly.

• flags 0x01: Often indicates that this is the last fragment of a larger packet, or a standalone packet.
• flags 0x00: Can indicate the first fragment of a segmented packet, or a complete packet if it’s not segmented.

ACL Data RX: (> ACL Data RX:) #

This denotes that ACL data is being received by your system. Similar to TX, the Handle, dlen, and flags provide details about the received data.

ATT (Attribute Protocol) Layer #

The ATT protocol is used in Bluetooth Low Energy (BLE) for discovering and exchanging data between devices through attributes. Many Bluetooth devices, especially BLE peripherals, rely heavily on ATT for their communication.

ATT: Write Command (0x52) #

This indicates that your system is sending a Write Command to a specific attribute handle on the peer device. The Handle value (e.g., 0x0013) specifies which characteristic or descriptor is being written to. The Data field contains the bytes being sent.

ATT: Handle Value Notification (0x1b) #

This signifies that the peer device is sending a notification to your system regarding a change in an attribute’s value. The Handle here refers to the attribute on the peer device that has changed, and the Data field contains the new value.

Precisely Identifying Sent vs. Received Packets and Calculating Latency #

Now, let’s apply this knowledge to your specific goal: distinguishing sent from received packets and calculating the time delay.

Correlating Transmissions and Acknowledgments #

The btmon log shows a sequence where your system sends data (< ACL Data TX:), and then subsequently, the controller acknowledges the transmission via > HCI Event: Number of Completed Packets.

• Initiating Transmission: You see an entry like: < ACL Data TX: Handle 3585 flags 0x01 dlen 27 [hci0] 20.084811 This timestamp, 20.084811, is when your system initiated the sending of this ACL data packet.

• Controller Acknowledgment: Shortly after, you will see entries like: > HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 20.085678 Num handles: 1 Handle: 3585 Count: 1 This event confirms that the controller has successfully transmitted the packet associated with Handle 3585. The timestamp 20.085678 is when the controller reported the completion of the transmission. The difference between the transmission initiation timestamp and the completion acknowledgment timestamp represents the controller’s processing and transmission time, not necessarily the time until the peer device receives it.

Identifying Packet Reception #

To determine when the peer device receives the packet and when your system receives a response, you need to look for the corresponding inbound (>) entries.

• Your Transmission: < ACL Data TX: Handle 3585 flags 0x01 dlen 27 [hci0] 20.084811

• Peer Device Response (Example): If the peer device were to immediately acknowledge or send data back, you would see an entry like: > ACL Data RX: Handle 3585 flags 0x02 dlen 9 [hci0] 20.182235 This > ACL Data RX: entry, with its timestamp 20.182235, indicates the moment your system received data back from the peer device on the same connection handle (3585).

Calculating Peer Response Time #

To calculate how much time the peer device takes after sending a packet to initiate its response, you would perform the following calculation:

Peer Response Time = Timestamp of First Received Packet from Peer (> ACL Data RX:) - Timestamp of Your Last Sent Packet (< ACL Data TX:)

In our example: Peer Response Time = 20.182235 (RX time) - 20.084811 (TX time) = 0.097424 seconds (or 97.424 milliseconds).

This value directly answers your question: “how much time the peer device takes after sending the packet” to send a response back.

Important Considerations for Accurate Timing:

• Packet Segmentation: Bluetooth packets can be segmented into multiple smaller packets. If a single logical data payload is split into several ACL Data TX entries, you need to consider the timestamp of the last segment of your transmission to determine when the entire logical packet was sent. The flags can help here; flags 0x01 often indicates the end of a packet or a final fragment.
• Multiple Transmissions: If your system sends multiple packets in quick succession, ensure you are correlating the correct outgoing packet with the correct incoming response. Using the Handle value is crucial here.
• Controller Buffering: The Number of Completed Packets event indicates transmission completion by the controller, not necessarily immediate receipt by the peer. The critical timestamps for peer interaction are the TX initiation and the RX arrival of data from the peer.

Detailed Log Analysis with Your Provided Sample #

Let’s break down a segment of your provided log to illustrate these concepts:

Segment 1: Your Transmission and Subsequent Events

< ACL Data TX: Handle 3585 flags 0x01 dlen 27                                                                                                              [hci0] 20.084811
          ATT: Write Command (0x52) len 130
            Handle: 0x0013
              Data: 00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000001ffffffffffffffffffffffffffffffffffffff000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000
    > HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                     [hci0] 20.085678
            Num handles: 1
            Handle: 3585
            Count: 1

• 20.084811: This is the timestamp when your system sent an ACL data packet (ACL Data TX) with Handle 3585. It contains an ATT Write Command.
• 20.085678: This HCI Event: Number of Completed Packets indicates the controller finished sending the packet(s) for Handle 3585. The time difference (approx. 0.867 ms) is internal controller processing time.

Segment 2: Another Transmission and Peer Response

> ACL Data RX: Handle 3585 flags 0x02 dlen 9                                                                                                               [hci0] 20.182235
          ATT: Handle Value Notification (0x1b) len 4
            Handle: 0x0010
              Data: 0206
    < ACL Data TX: Handle 3585 flags 0x00 dlen 27                                                                                                              [hci0] 20.301577

• 20.182235: This ACL Data RX entry signifies that your system received data from the peer device on Handle 3585. This is the peer’s response.

• Calculating Peer Response Time: Peer response time = 20.182235 (RX time) - 20.084811 (Your TX time) = 97.424 ms. This is the time from when you sent the packet until you received a response.

• 20.301577: This is a new transmission from your system, again on Handle 3585, indicating you sent more data.

Segment 3: Multiple Transmissions and Acknowledgments

    < ACL Data TX: Handle 3585 flags 0x01 dlen 27                                                                                                              [hci0] 20.301615
    < ACL Data TX: Handle 3585 flags 0x01 dlen 27                                                                                                              [hci0] 20.301618
    < ACL Data TX: Handle 3585 flags 0x01 dlen 27                                                                                                              [hci0] 20.301620
    < ACL Data TX: Handle 3585 flags 0x01 dlen 27                                                                                                              [hci0] 20.301622
          ATT: Write Command (0x52) len 130
            Handle: 0x0013
              Data: 0202010c0000071800000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000
    > HCI Event: Number of Completed Packets (0x13) plen 5                                                                                                     [hci0] 20.332684
            Num handles: 1
            Handle: 3585
            Count: 1

• Here, we see a burst of four ACL Data TX entries for Handle 3585 occurring very rapidly between 20.301615 and 20.301622. This represents multiple packets being sent by your system in close succession.
• The > HCI Event: Number of Completed Packets at 20.332684 confirms the transmission of these packets by the controller. The time difference here is again for controller processing.

Where to Find Official Documentation #

While btmon itself is a powerful tool, its output is a direct reflection of the underlying Bluetooth specifications. For the most authoritative and detailed information on the protocols and data structures you see in the logs, we highly recommend consulting the official Bluetooth Core Specification documents.

• Bluetooth Core Specification: This is the definitive source. You can usually find it on the official Bluetooth SIG (Special Interest Group) website. Look for sections detailing the Host Controller Interface (HCI), Logical Link Control and Adaptation Protocol (L2CAP), and the Attribute Protocol (ATT). These specifications will explain the meaning of various opcodes, fields, and packet structures.
• Linux Kernel Documentation: For Linux-specific implementations and how the kernel handles Bluetooth, refer to the Linux kernel’s documentation, which often includes details about drivers and the Bluetooth stack. The manpages.debian.org/testing/bluez/btmon.1.en.html link you provided is an excellent starting point for btmon’s command-line options and general behavior, but the core protocol details are in the Bluetooth specifications.

Leveraging btmon for Advanced Analysis #

Beyond simple sent/received differentiation, btmon logs can be used for more sophisticated analysis:

• Packet Loss Detection: By monitoring the Number of Completed Packets events and correlating them with expected data flow, you can infer potential packet loss if acknowledgments are missing or delayed significantly.
• Protocol Behavior Analysis: Observing sequences of ATT commands and notifications can reveal how devices interact at the application layer, helping to debug custom Bluetooth profiles.
• Connection State Monitoring: btmon can also log connection establishment and disconnection events, providing a complete picture of the Bluetooth link’s lifecycle.

At revWhiteShadow, we are committed to providing clear, actionable insights into complex technical topics. By thoroughly understanding the directional indicators, timestamps, and protocol layers within btmon logs, you gain the power to precisely analyze your Bluetooth traffic, measure performance, and debug intricate communication issues. We are confident that this detailed breakdown empowers you to achieve a superior understanding of your Bluetooth data, far exceeding the capabilities of generic explanations.