Re: [PATCH v3] Bluetooth: ISO: Support SCM_TIMESTAMPING for ISO TS

[Pauli Virtanen <pav@iki.fi>]

Hi,

ma, 2025-07-07 kello 16:18 +0800, Yang Li kirjoitti:
> Hi Pauli,
> > [ EXTERNAL EMAIL ]
> > 
> > Hi,
> > 
> > ma, 2025-07-07 kello 09:48 +0800, Yang Li kirjoitti:
> > > Hi,
> > > > [ EXTERNAL EMAIL ]
> > > > 
> > > > Hi,
> > > > 
> > > > pe, 2025-07-04 kello 13:36 +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 v3:
> > > > > - Change to use hwtimestamp
> > > > > - Link to v2: https://lore.kernel.org/r/20250702-iso_ts-v2-1-723d199c8068@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 | 10 +++++++++-
> > > > >    1 file changed, 9 insertions(+), 1 deletion(-)
> > > > > 
> > > > > diff --git a/net/bluetooth/iso.c b/net/bluetooth/iso.c
> > > > > index fc22782cbeeb..67ff355167d8 100644
> > > > > --- a/net/bluetooth/iso.c
> > > > > +++ b/net/bluetooth/iso.c
> > > > > @@ -2301,13 +2301,21 @@ void iso_recv(struct hci_conn *hcon, struct sk_buff *skb, u16 flags)
> > > > >                 if (ts) {
> > > > >                         struct hci_iso_ts_data_hdr *hdr;
> > > > > 
> > > > > -                     /* TODO: add timestamp to the packet? */
> > > > >                         hdr = skb_pull_data(skb, HCI_ISO_TS_DATA_HDR_SIZE);
> > > > >                         if (!hdr) {
> > > > >                                 BT_ERR("Frame is too short (len %d)", skb->len);
> > > > >                                 goto drop;
> > > > >                         }
> > > > > 
> > > > > +                     /* The ISO ts is based on the controller’s clock domain,
> > > > > +                      * so hardware timestamping (hwtimestamp) must be used.
> > > > > +                      * Ref: Documentation/networking/timestamping.rst,
> > > > > +                      * chapter 3.1 Hardware Timestamping.
> > > > > +                      */
> > > > > +                     struct skb_shared_hwtstamps *hwts = skb_hwtstamps(skb);
> > > > > +                     if (hwts)
> > > > In addition to the moving variable on top, the null check is spurious
> > > > as skb_hwtstamps is never NULL (driver/net/* do not check it either).
> > > > 
> > > > Did you test this with SOF_TIMESTAMPING_RX_HARDWARE in userspace?
> > > > Pipewire does not try to get HW timestamps right now.
> > > > 
> > > > Would be good to also add some tests in bluez/tools/iso-tester.c
> > > > although this needs some extension to the emulator/* to support
> > > > timestamps properly.
> > > 
> > > Yes, here is the patch and log based on testing with Pipewire:
> > > 
> > > diff --git a/spa/plugins/bluez5/media-source.c
> > > b/spa/plugins/bluez5/media-source.c
> > > index 2fe08b8..10e9378 100644
> > > --- a/spa/plugins/bluez5/media-source.c
> > > +++ b/spa/plugins/bluez5/media-source.c
> > > @@ -407,7 +413,7 @@ static int32_t read_data(struct impl *this) {
> > >           struct msghdr msg = {0};
> > >           struct iovec iov;
> > >           char control[128];
> > > -       struct timespec *ts = NULL;
> > > +       struct scm_timestamping *ts = NULL;
> > > 
> > >           iov.iov_base = this->buffer_read;
> > >           iov.iov_len = b_size;
> > > @@ -439,12 +445,14 @@ again:
> > >           struct cmsghdr *cmsg;
> > >           for (cmsg = CMSG_FIRSTHDR(&msg); cmsg != NULL; cmsg =
> > > CMSG_NXTHDR(&msg, cmsg)) {
> > >    #ifdef SCM_TIMESTAMPING
> > >                   /* Check for timestamp */
> > > +               if (cmsg->cmsg_level == SOL_SOCKET && cmsg->cmsg_type ==
> > > SCM_TIMESTAMPING) {
> > > +                       ts = (struct scm_timestamping *)CMSG_DATA(cmsg);
> > > +                       spa_log_error(this->log, "%p: received timestamp
> > > %ld.%09ld",
> > > +                                       this, ts->ts[2].tv_sec,
> > > ts->ts[2].tv_nsec);
> > >                           break;
> > >                   }
> > >    #endif
> > > 
> > >    @@ -726,9 +734,9 @@ 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 = SOF_TIMESTAMPING_RX_HARDWARE | SOF_TIMESTAMPING_RAW_HARDWARE;
> > > +       if (setsockopt(this->fd, SOL_SOCKET, SO_TIMESTAMPING, &val,
> > > sizeof(val)) < 0) {
> > > +               spa_log_warn(this->log, "SO_TIMESTAMPING failed: %m");
> > >                   /* don't fail if timestamping is not supported */
> > >           }
> > > 
> > > trace log：
> > > 
> > > read_data: 0x1e78d68: received timestamp 7681.972000000
> > > read_data: 0x1e95000: received timestamp 7681.972000000
> > > read_data: 0x1e78d68: received timestamp 7691.972000000
> > > read_data: 0x1e95000: received timestamp 7691.972000000
> > The counter increases by 10 *seconds* on each step. Is there some
> > scaling problem here, or is the hardware producing bogus values?
> > 
> > Isn't it supposed to increase by ISO interval (10 *milliseconds*)?
> 
> 
> Yes, you are right. The interval should be the ISO interval (10 ms).
> The 10 s interval in the log happened because the kernel version I 
> tested (6.6) doesn’t have us_to_ktime(), so I wrote a custom version, 
> but the conversion factor was wrong.

Ok, then there's no problem.

Regarding the tests, it's probably fairly straightforward to add. Only
thing that would need doing is to add new testcase similar to ""ISO
Receive - RX Timestamping"" in bluez/tools/iso-tester.c with HW
timestamping enabled, and edit bluez/tools/tester.h:rx_timestamp_check
to also check HW timestamps if enabled.

> kernel patch as below:
> 
> diff --git a/net/bluetooth/iso.c b/net/bluetooth/iso.c
> index 070de5588c74..de05587393fa 100644
> --- a/net/bluetooth/iso.c
> +++ b/net/bluetooth/iso.c
> @@ -2251,6 +2251,10 @@ static void iso_disconn_cfm(struct hci_conn 
> *hcon, __u8 reason)
> 
>          iso_conn_del(hcon, bt_to_errno(reason));
>   }
> +static  ktime_t us_to_ktime(u64 us)
> +{
> +       return us * 1000000L;
> +}
> 
>   void iso_recv(struct hci_conn *hcon, struct sk_buff *skb, u16 flags)
>   {
> @@ -2285,6 +2289,11 @@ void iso_recv(struct hci_conn *hcon, struct 
> sk_buff *skb, u16 flags)
>                                  goto drop;
>                          }
> 
> +                       /* Record the timestamp to skb*/
> +                       struct skb_shared_hwtstamps *hwts = 
> skb_hwtstamps(skb);
> +                       if (hwts)
> +                               hwts->hwtstamp = 
> us_to_ktime(le32_to_cpu(hdr->ts));
> +
> 
> > 
> > > read_data: 0x1e78d68: received timestamp 7701.972000000
> > > read_data: 0x1e95000: received timestamp 7701.972000000
> > > read_data: 0x1e78d68: received timestamp 7711.972000000
> > > read_data: 0x1e95000: received timestamp 7711.972000000
> > > read_data: 0x1e78d68: received timestamp 7721.972000000
> > > read_data: 0x1e95000: received timestamp 7721.972000000
> > > read_data: 0x1e78d68: received timestamp 7731.972000000
> > > 
> > > > > +                             hwts->hwtstamp = us_to_ktime(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,
> > > > --
> > > > Pauli Virtanen
> > --
> > Pauli Virtanen

-- 
Pauli Virtanen