Bluetooth: ISO: Support SOCK_RCVTSTAMP via CMSG for ISO sockets

[PATCH v2] Bluetooth: ISO: Support SOCK_RCVTSTAMP via CMSG for ISO sockets

Posted by Yang Li via B4 Relay 3 months, 1 week ago

From: Yang Li <yang.li@amlogic.com>

User-space applications (e.g., PipeWire) depend on
ISO-formatted timestamps for precise audio sync.

Signed-off-by: Yang Li <yang.li@amlogic.com>
---
Changes in v2:
- Support SOCK_RCVTSTAMPNS via CMSG for ISO sockets
- Link to v1: https://lore.kernel.org/r/20250429-iso_ts-v1-1-e586f30de6cb@amlogic.com
---
 net/bluetooth/iso.c | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/net/bluetooth/iso.c b/net/bluetooth/iso.c
index fc22782cbeeb..6927c593a1d6 100644
--- a/net/bluetooth/iso.c
+++ b/net/bluetooth/iso.c
@@ -2308,6 +2308,9 @@ void iso_recv(struct hci_conn *hcon, struct sk_buff *skb, u16 flags)
 				goto drop;
 			}
 
+			/* Record the timestamp to skb*/
+			skb->skb_mstamp_ns = le32_to_cpu(hdr->ts);
+
 			len = __le16_to_cpu(hdr->slen);
 		} else {
 			struct hci_iso_data_hdr *hdr;

---
base-commit: 3bc46213b81278f3a9df0324768e152de71eb9fe
change-id: 20250421-iso_ts-c82a300ae784

Best regards,
-- 
Yang Li <yang.li@amlogic.com>

Re: [PATCH v2] Bluetooth: ISO: Support SOCK_RCVTSTAMP via CMSG for ISO sockets

Posted by Pauli Virtanen 3 months, 1 week ago

Hi,

ke, 2025-07-02 kello 19:35 +0800, Yang Li via B4 Relay kirjoitti:
> From: Yang Li <yang.li@amlogic.com>
> 
> User-space applications (e.g., PipeWire) depend on
> ISO-formatted timestamps for precise audio sync.
> 
> Signed-off-by: Yang Li <yang.li@amlogic.com>
> ---
> Changes in v2:
> - Support SOCK_RCVTSTAMPNS via CMSG for ISO sockets
> - Link to v1: https://lore.kernel.org/r/20250429-iso_ts-v1-1-e586f30de6cb@amlogic.com
> ---
>  net/bluetooth/iso.c | 3 +++
>  1 file changed, 3 insertions(+)
> 
> diff --git a/net/bluetooth/iso.c b/net/bluetooth/iso.c
> index fc22782cbeeb..6927c593a1d6 100644
> --- a/net/bluetooth/iso.c
> +++ b/net/bluetooth/iso.c
> @@ -2308,6 +2308,9 @@ void iso_recv(struct hci_conn *hcon, struct sk_buff *skb, u16 flags)
>  				goto drop;
>  			}
>  
> +			/* Record the timestamp to skb*/
> +			skb->skb_mstamp_ns = le32_to_cpu(hdr->ts);

Hardware timestamps are supposed to go in

	skb_hwtstamps(skb)->hwtstamp

See Documentation/networking/timestamping.rst
"3.1 Hardware Timestamping Implementation: Device Drivers" and how it
is done in drivers/net/

This documentation also explains how user applications can obtain the
hardware timestamps.

AFAIK, skb->tstamp (skb->skb_mstamp_ns is union for it) must be in
system clock. The hdr->ts is in some unsynchronized controller clock,
so they should go to HW timestamps.

> +
>  			len = __le16_to_cpu(hdr->slen);
>  		} else {
>  			struct hci_iso_data_hdr *hdr;
> 
> ---
> base-commit: 3bc46213b81278f3a9df0324768e152de71eb9fe
> change-id: 20250421-iso_ts-c82a300ae784
> 
> Best regards,

-- 
Pauli Virtanen

Re: [PATCH v2] Bluetooth: ISO: Support SOCK_RCVTSTAMP via CMSG for ISO sockets

Posted by Yang Li 3 months ago

Hi,
> [ EXTERNAL EMAIL ]
>
> Hi,
>
> ke, 2025-07-02 kello 19:35 +0800, Yang Li via B4 Relay kirjoitti:
>> From: Yang Li <yang.li@amlogic.com>
>>
>> User-space applications (e.g., PipeWire) depend on
>> ISO-formatted timestamps for precise audio sync.
>>
>> Signed-off-by: Yang Li <yang.li@amlogic.com>
>> ---
>> Changes in v2:
>> - Support SOCK_RCVTSTAMPNS via CMSG for ISO sockets
>> - Link to v1: https://lore.kernel.org/r/20250429-iso_ts-v1-1-e586f30de6cb@amlogic.com
>> ---
>>   net/bluetooth/iso.c | 3 +++
>>   1 file changed, 3 insertions(+)
>>
>> diff --git a/net/bluetooth/iso.c b/net/bluetooth/iso.c
>> index fc22782cbeeb..6927c593a1d6 100644
>> --- a/net/bluetooth/iso.c
>> +++ b/net/bluetooth/iso.c
>> @@ -2308,6 +2308,9 @@ void iso_recv(struct hci_conn *hcon, struct sk_buff *skb, u16 flags)
>>                                goto drop;
>>                        }
>>
>> +                     /* Record the timestamp to skb*/
>> +                     skb->skb_mstamp_ns = le32_to_cpu(hdr->ts);
> Hardware timestamps are supposed to go in
>
>          skb_hwtstamps(skb)->hwtstamp
>
> See Documentation/networking/timestamping.rst
> "3.1 Hardware Timestamping Implementation: Device Drivers" and how it
> is done in drivers/net/
>
> This documentation also explains how user applications can obtain the
> hardware timestamps.
>
> AFAIK, skb->tstamp (skb->skb_mstamp_ns is union for it) must be in
> system clock. The hdr->ts is in some unsynchronized controller clock,
> so they should go to HW timestamps.


Following your suggestion, I switched to hwtstamp but kept 
SO_TIMESTAMPNS on the PipeWire side.

+                       struct skb_shared_hwtstamps *hwts = 
skb_hwtstamps(skb);
+                       if (hwts)
+                               hwts->hwtstamp = 
us_to_ktime(le32_to_cpu(hdr->ts));
+

The value I get is unexpectedly large and not the same as the timestamp 
in the ISO data.

read_data: received timestamp: 880608.479272966
read_data: received timestamp: 880608.479438633
read_data: received timestamp: 880608.489259466
read_data: received timestamp: 880608.489434550
read_data: received timestamp: 880608.499289258
read_data: received timestamp: 880608.499464550
read_data: received timestamp: 880608.509278008
read_data: received timestamp: 880608.509451425
read_data: received timestamp: 880608.519261175
read_data: received timestamp: 880608.519438633
read_data: received timestamp: 880608.529385008
read_data: received timestamp: 880608.529462133
read_data: received timestamp: 880608.539273758
read_data: received timestamp: 880608.539452758
read_data: received timestamp: 880608.549271258
read_data: received timestamp: 880608.549450008
read_data: received timestamp: 880608.559263466
read_data: received timestamp: 880608.559443216
read_data: received timestamp: 880608.569257466


Is there any special processing in the application code?

>
>> +
>>                        len = __le16_to_cpu(hdr->slen);
>>                } else {
>>                        struct hci_iso_data_hdr *hdr;
>>
>> ---
>> base-commit: 3bc46213b81278f3a9df0324768e152de71eb9fe
>> change-id: 20250421-iso_ts-c82a300ae784
>>
>> Best regards,
> --
> Pauli Virtanen

Re: [PATCH v2] Bluetooth: ISO: Support SOCK_RCVTSTAMP via CMSG for ISO sockets

Posted by Pauli Virtanen 3 months ago

Hi,

3. heinäkuuta 2025 10.34.46 UTC Yang Li <yang.li@amlogic.com> kirjoitti:
>Hi,
>> [ EXTERNAL EMAIL ]
>> 
>> Hi,
>> 
>> ke, 2025-07-02 kello 19:35 +0800, Yang Li via B4 Relay kirjoitti:
>>> From: Yang Li <yang.li@amlogic.com>
>>> 
>>> User-space applications (e.g., PipeWire) depend on
>>> ISO-formatted timestamps for precise audio sync.
>>> 
>>> Signed-off-by: Yang Li <yang.li@amlogic.com>
>>> ---
>>> Changes in v2:
>>> - Support SOCK_RCVTSTAMPNS via CMSG for ISO sockets
>>> - Link to v1: https://lore.kernel.org/r/20250429-iso_ts-v1-1-e586f30de6cb@amlogic.com
>>> ---
>>>   net/bluetooth/iso.c | 3 +++
>>>   1 file changed, 3 insertions(+)
>>> 
>>> diff --git a/net/bluetooth/iso.c b/net/bluetooth/iso.c
>>> index fc22782cbeeb..6927c593a1d6 100644
>>> --- a/net/bluetooth/iso.c
>>> +++ b/net/bluetooth/iso.c
>>> @@ -2308,6 +2308,9 @@ void iso_recv(struct hci_conn *hcon, struct sk_buff *skb, u16 flags)
>>>                                goto drop;
>>>                        }
>>> 
>>> +                     /* Record the timestamp to skb*/
>>> +                     skb->skb_mstamp_ns = le32_to_cpu(hdr->ts);
>> Hardware timestamps are supposed to go in
>> 
>>          skb_hwtstamps(skb)->hwtstamp
>> 
>> See Documentation/networking/timestamping.rst
>> "3.1 Hardware Timestamping Implementation: Device Drivers" and how it
>> is done in drivers/net/
>> 
>> This documentation also explains how user applications can obtain the
>> hardware timestamps.
>> 
>> AFAIK, skb->tstamp (skb->skb_mstamp_ns is union for it) must be in
>> system clock. The hdr->ts is in some unsynchronized controller clock,
>> so they should go to HW timestamps.
>
>
>Following your suggestion, I switched to hwtstamp but kept SO_TIMESTAMPNS on the PipeWire side.
>
>+                       struct skb_shared_hwtstamps *hwts = skb_hwtstamps(skb);
>+                       if (hwts)
>+                               hwts->hwtstamp = us_to_ktime(le32_to_cpu(hdr->ts));
>+
>
>The value I get is unexpectedly large and not the same as the timestamp in the ISO data.

The value given by SO_TIMESTAMPNS is the system clock time when kernel received the packet.

It's not the same as the ISO timestamp, as the ISO TS is in controller clock. This is normal. Applications generally need timestamps in system clock.

The two clocks are not synchronized. There is an unknown offset between system clock and ISO TS times. AFAIK there is no specified way to find what it is precisely (= synchronize clocks) using HCI. This appears implementation-defined. So I think kernel should report both timestamps, and leave it to applications to try to correlate them.

Note that master branch of Pipewire already uses the kernel-provided RX timestamps. It can use also the HW timestamps after they are added. They likely improve CIS synchronization, as it's then unambiguous which packets belong together and we can correlate all CIS using same clock matching.

>
>read_data: received timestamp: 880608.479272966
>read_data: received timestamp: 880608.479438633
>read_data: received timestamp: 880608.489259466
>read_data: received timestamp: 880608.489434550
>read_data: received timestamp: 880608.499289258
>read_data: received timestamp: 880608.499464550
>read_data: received timestamp: 880608.509278008
>read_data: received timestamp: 880608.509451425
>read_data: received timestamp: 880608.519261175
>read_data: received timestamp: 880608.519438633
>read_data: received timestamp: 880608.529385008
>read_data: received timestamp: 880608.529462133
>read_data: received timestamp: 880608.539273758
>read_data: received timestamp: 880608.539452758
>read_data: received timestamp: 880608.549271258
>read_data: received timestamp: 880608.549450008
>read_data: received timestamp: 880608.559263466
>read_data: received timestamp: 880608.559443216
>read_data: received timestamp: 880608.569257466
>
>
>Is there any special processing in the application code?
>
>> 
>>> +
>>>                        len = __le16_to_cpu(hdr->slen);
>>>                } else {
>>>                        struct hci_iso_data_hdr *hdr;
>>> 
>>> ---
>>> base-commit: 3bc46213b81278f3a9df0324768e152de71eb9fe
>>> change-id: 20250421-iso_ts-c82a300ae784
>>> 
>>> Best regards,
>> --
>> Pauli Virtanen

Re: [PATCH v2] Bluetooth: ISO: Support SOCK_RCVTSTAMP via CMSG for ISO sockets

Posted by Paul Menzel 3 months, 1 week ago

Dear Li,


Thank you for your patch.


Am 02.07.25 um 13:35 schrieb Yang Li via B4 Relay:
> From: Yang Li <yang.li@amlogic.com>
> 
> User-space applications (e.g., PipeWire) depend on
> ISO-formatted timestamps for precise audio sync.

Does PipeWire log anything? It’d be great if you could add how to 
reproduce the issue including the PipeWire version.

> Signed-off-by: Yang Li <yang.li@amlogic.com>
> ---
> Changes in v2:
> - Support SOCK_RCVTSTAMPNS via CMSG for ISO sockets
> - Link to v1: https://lore.kernel.org/r/20250429-iso_ts-v1-1-e586f30de6cb@amlogic.com
> ---
>   net/bluetooth/iso.c | 3 +++
>   1 file changed, 3 insertions(+)
> 
> diff --git a/net/bluetooth/iso.c b/net/bluetooth/iso.c
> index fc22782cbeeb..6927c593a1d6 100644
> --- a/net/bluetooth/iso.c
> +++ b/net/bluetooth/iso.c
> @@ -2308,6 +2308,9 @@ void iso_recv(struct hci_conn *hcon, struct sk_buff *skb, u16 flags)
>   				goto drop;
>   			}
>   
> +			/* Record the timestamp to skb*/
> +			skb->skb_mstamp_ns = le32_to_cpu(hdr->ts);
> +
>   			len = __le16_to_cpu(hdr->slen);
>   		} else {
>   			struct hci_iso_data_hdr *hdr;

Kind regards,

Paul

Re: [PATCH v2] Bluetooth: ISO: Support SOCK_RCVTSTAMP via CMSG for ISO sockets

Posted by Yang Li 3 months, 1 week ago

Hi Paul,
> [ EXTERNAL EMAIL ]
>
> Dear Li,
>
>
> Thank you for your patch.
>
>
> Am 02.07.25 um 13:35 schrieb Yang Li via B4 Relay:
>> From: Yang Li <yang.li@amlogic.com>
>>
>> User-space applications (e.g., PipeWire) depend on
>> ISO-formatted timestamps for precise audio sync.
>
> Does PipeWire log anything? It’d be great if you could add how to
> reproduce the issue including the PipeWire version.


Pipewire version: 1.2.7

I have modified the patch as follows:

diff --git a/spa/plugins/bluez5/media-source.c 
b/spa/plugins/bluez5/media-source.c
index 488cf49..2fe08b8 100644
--- a/spa/plugins/bluez5/media-source.c
+++ b/spa/plugins/bluez5/media-source.c
@@ -404,9 +404,22 @@ static int32_t read_data(struct impl *this) {
      const ssize_t b_size = sizeof(this->buffer_read);
      int32_t size_read = 0;

+    struct msghdr msg = {0};
+    struct iovec iov;
+    char control[128];
+    struct timespec *ts = NULL;
+
+    iov.iov_base = this->buffer_read;
+    iov.iov_len = b_size;
+
+    msg.msg_iov = &iov;
+    msg.msg_iovlen = 1;
+    msg.msg_control = control;
+    msg.msg_controllen = sizeof(control);
+
  again:
-    /* read data from socket */
-    size_read = recv(this->fd, this->buffer_read, b_size, MSG_DONTWAIT);
+    /* read data from socket, with timestamp */
+    size_read = recvmsg(this->fd, &msg, MSG_DONTWAIT);

      if (size_read == 0)
          return 0;
@@ -417,13 +430,26 @@ again:

          /* return socket has no data */
          if (errno == EAGAIN || errno == EWOULDBLOCK)
-            return 0;
+            return 0;

          /* go to 'stop' if socket has an error */
          spa_log_error(this->log, "read error: %s", strerror(errno));
          return -errno;
      }

+    struct cmsghdr *cmsg;
+    for (cmsg = CMSG_FIRSTHDR(&msg); cmsg != NULL; cmsg = 
CMSG_NXTHDR(&msg, cmsg)) {
+#ifdef SO_TIMESTAMPNS
+        /* Check for timestamp */
+        if (cmsg->cmsg_level == SOL_SOCKET && cmsg->cmsg_type == 
SO_TIMESTAMPNS) {
+            ts = (struct timespec *)CMSG_DATA(cmsg);
+            spa_log_trace(this->log, "%p: received timestamp %ld.%09ld",
+                    this, (long)ts->tv_sec, (long)ts->tv_nsec);
+            break;
+        }
+#endif
+    }
+
      return size_read;
  }

@@ -700,6 +726,12 @@ static int transport_start(struct impl *this)
      if (setsockopt(this->fd, SOL_SOCKET, SO_PRIORITY, &val, 
sizeof(val)) < 0)
          spa_log_warn(this->log, "SO_PRIORITY failed: %m");

+    val = 1;
+    if (setsockopt(this->fd, SOL_SOCKET, SO_TIMESTAMPNS, &val, 
sizeof(val)) < 0) {
+        spa_log_warn(this->log, "SO_TIMESTAMPNS failed: %m");
+        /* don't fail if timestamping is not supported */
+    }
+
      reset_buffers(port);

      spa_bt_decode_buffer_clear(&port->buffer);


Pipewire log as below:

03:40:00.850312 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017361972
03:40:00.850571 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017361972
03:40:00.860241 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017371972
03:40:00.860430 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017371972
03:40:00.870166 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017381972
03:40:00.870343 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017381972
03:40:00.880197 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017391972
03:40:00.880370 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017391972
03:40:00.890405 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017401972
03:40:00.890642 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017401972
03:40:00.900201 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017411972
03:40:00.900652 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017411972
03:40:00.910391 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017421972
03:40:00.910694 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017421972
03:40:00.920198 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017431972
03:40:00.920352 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017431972
03:40:00.930438 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017441972
03:40:00.930699 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017441972
03:40:00.940171 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017451972
03:40:00.940331 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017451972
03:40:00.950427 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017461972
03:40:00.950678 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017461972
03:40:00.960447 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017471972
03:40:00.960703 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017471972
03:40:00.970154 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017481972
03:40:00.970308 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017481972
03:40:00.980443 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017491972
03:40:00.980667 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017491972
03:40:00.990455 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017501972
03:40:00.990706 spa.bluez5.source. 
../spa/plugins/bluez5/media-source.c:450:read_data: received timestamp: 
0.017501972

>
>> Signed-off-by: Yang Li <yang.li@amlogic.com>
>> ---
>> Changes in v2:
>> - Support SOCK_RCVTSTAMPNS via CMSG for ISO sockets
>> - Link to v1: 
>> https://lore.kernel.org/r/20250429-iso_ts-v1-1-e586f30de6cb@amlogic.com
>> ---
>>   net/bluetooth/iso.c | 3 +++
>>   1 file changed, 3 insertions(+)
>>
>> diff --git a/net/bluetooth/iso.c b/net/bluetooth/iso.c
>> index fc22782cbeeb..6927c593a1d6 100644
>> --- a/net/bluetooth/iso.c
>> +++ b/net/bluetooth/iso.c
>> @@ -2308,6 +2308,9 @@ void iso_recv(struct hci_conn *hcon, struct 
>> sk_buff *skb, u16 flags)
>>                               goto drop;
>>                       }
>>
>> +                     /* Record the timestamp to skb*/
>> +                     skb->skb_mstamp_ns = le32_to_cpu(hdr->ts);
>> +
>>                       len = __le16_to_cpu(hdr->slen);
>>               } else {
>>                       struct hci_iso_data_hdr *hdr;
>
> Kind regards,
>
> Paul