[xdp-hints] Re: [PATCH bpf-next V1 5/5] selftests/bpf: xdp_hw_metadata track more timestamps

[Kurt Kanzenbach <kurt.kanzenbach@linutronix.de>]

[-- Attachment #1: Type: text/plain, Size: 4453 bytes --]

On Tue Apr 18 2023, Jesper Dangaard Brouer wrote:
> On 17/04/2023 17.31, Kurt Kanzenbach wrote:
>> On Mon Apr 17 2023, Jesper Dangaard Brouer wrote:
>>> To correlate the hardware RX timestamp with something, add tracking of
>>> two software timestamps both clock source CLOCK_TAI (see description in
>>> man clock_gettime(2)).
>>>
>>> XDP metadata is extended with xdp_timestamp for capturing when XDP
>>> received the packet. Populated with BPF helper bpf_ktime_get_tai_ns(). I
>>> could not find a BPF helper for getting CLOCK_REALTIME, which would have
>>> been preferred. In userspace when AF_XDP sees the packet another
>>> software timestamp is recorded via clock_gettime() also clock source
>>> CLOCK_TAI.
>>>
>>> Example output shortly after loading igc driver:
>>>
>>>    poll: 1 (0) skip=1 fail=0 redir=2
>>>    xsk_ring_cons__peek: 1
>>>    0x12557a8: rx_desc[1]->addr=100000000009000 addr=9100 comp_addr=9000
>>>    rx_hash: 0x82A96531 with RSS type:0x1
>>>    rx_timestamp:  1681740540304898909 (sec:1681740540.3049)
>>>    XDP RX-time:   1681740577304958316 (sec:1681740577.3050) delta sec:37.0001 (37000059.407 usec)
>>>    AF_XDP time:   1681740577305051315 (sec:1681740577.3051) delta sec:0.0001 (92.999 usec)
>>>    0x12557a8: complete idx=9 addr=9000
>>>
>>> The first observation is that the 37 sec difference between RX HW vs XDP
>>> timestamps, which indicate hardware is likely clock source
>>> CLOCK_REALTIME, because (as of this writing) CLOCK_TAI is initialised
>>> with a 37 sec offset.
>> 
>> Maybe I'm missing something here, but in order to compare the hardware
>> with software timestamps (e.g., by using bpf_ktime_get_tai_ns()) the
>> time sources have to be synchronized by using something like
>> phc2sys. That should make them comparable within reasonable range
>> (nanoseconds).
>
> Precisely, in this test I've not synchronized the clocks.
> The observation is that driver igc clock gets initialized to
> CLOCK_REALTIME wall-clock time

Yes. The igc driver uses ktime_get_real() to initialize the PHC time in
init() and reset(). However, that's driver specific. PTP is based on
TAI.

>, and it slowly drifts as documented in provided link[1].

Yes, it does without proper synchronization. Linux has its own
independent system clock. Therefore, tools like phc2sys are required.

>
>   [1] 
> https://github.com/xdp-project/xdp-project/blob/master/areas/hints/xdp_hints_kfuncs02_driver_igc.org#driver-igc-clock-drift-observations
>   [2] 
> https://github.com/xdp-project/xdp-project/blob/master/areas/hints/xdp_hints_kfuncs02_driver_igc.org#quick-time-sync-setup
>
> I've also played with using phc2sys (in same doc[2]) to sync HW clock
> with SW clock. I do *seek input* if I'm using it correctly?!?.

Looks correct.

>
> I don't have a PTP clock setup , so I manually: Use phc2sys to
> synchronize the system clock to the PTP hardware clock (PHC) on the
> network card (which driver inited to CLOCK_REALTIME wall-clock).
>
> Stop ntp clock sync and disable most CPU sleep states:
>
>    sudo systemctl stop chronyd
>    sudo tuned-adm profile latency-performance
>    sudo hexdump --format '"%d\n"' /dev/cpu_dma_latency
>    2
>
> Adjust for the 37 sec offset to TAI, such that our BPF-prog using TAI 
> will align:
>
>    sudo phc2sys -s igc1 -O -37 -R 2 -u 10
>
> Result on igc with xdp_hw_metadata:
>
>   poll: 1 (0) skip=1 fail=0 redir=6
>   xsk_ring_cons__peek: 1
>   rx_hash: 0x82A96531 with RSS type:0x1
>   rx_timestamp:  1681825632645744805 (sec:1681825632.6457)
>   XDP RX-time:   1681825632645755858 (sec:1681825632.6458) delta 
> sec:0.0000 (11.053 usec)
>   AF_XDP time:   1681825632645769371 (sec:1681825632.6458) delta 
> sec:0.0000 (13.513 usec)
>
> The log file from phc2sys says:
>
>   phc2sys[1294263]: [86275.140] CLOCK_REALTIME rms    6 max   11 freq 
> +13719 +/-   5 delay  1435 +/-   5
>
> Notice the delta between HW and SW timestamps is 11.053 usec.
> Even-though it is small, I don't really trust it, because the phc2sys
> log says frequency offset mean is "+13719" nanosec.

The offset between the system and PHC clock is 11ns at maximum (and 6ns
in mean) which is quite good. The frequency offset is displayed in ppb.

>
> So, it is true that latency/delay between HW to XDP-SW is 11 usec?

I think so.

> Or is this due to (in)accuracy of phc2sys sync?

Nope.

Thanks,
Kurt

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 873 bytes --]