Re: dumpcap: timestamp is years ahead when in pcapng format

[Isaac Boukris <iboukris@gmail.com>]

I figured the first packet bug, fixed with:
-       if (!pcapng_time.tsc_hz)
+       if (!pcapng_time.tsc_hz) {
                pcapng_init();
+               return pcapng_time.ns;
+       }

However I noticed a caveat with my proposed fix as it seem we only get
a time resolution of one sec:

2023-09-20 09:40:20.727638 IP Rocky8 > A: ICMP echo request, id 11,
seq 81, length 64
2023-09-20 09:40:20.727638 IP A > Rocky8: ICMP echo reply, id 11, seq
81, length 64
2023-09-20 09:40:21.727638 IP ...

On Wed, Sep 20, 2023 at 8:59 PM Isaac Boukris <iboukris@gmail.com> wrote:
>
> On Tue, Sep 19, 2023 at 9:00 PM Stephen Hemminger
> <stephen@networkplumber.org> wrote:
> >
> > On Tue, 19 Sep 2023 19:35:55 +0300
> > Isaac Boukris <iboukris@gmail.com> wrote:
> >
> > > Looking with git log, i found the original line was:
> > > return pcapng_time.ns + (delta * NSEC_PER_SEC) / rte_get_tsc_hz();
> > >
> > > Testing that does show a wrapping issue, e.g. (it stays around 08:05).
> > >
> > > 2023-09-19 08:05:24.372037 IP _gateway.domain > Rocky8.38358: 31975
> > > NXDomain 0/0/0 (46)                                              10
> > > 2023-09-19 08:05:21.577497 ARP, Request who-has _gateway tell Rocky8,
> > > length 46
> > > 2023-09-19 08:05:21.577599 ARP, Reply _gateway is-at 00:50:56:f8:92:76
> > > (oui Unknown), length 46                                     13
> > > 2023-09-19 08:05:22.833897 IP 192.168.202.1.50886 >
> > > 239.255.255.250.ssdp: UDP, length 174
> > >
> > > However with my change it looks fine and always increments. I dropped
> > > all the parenthesis:
> > > return pcapng_time.ns + delta / pcapng_time.tsc_hz * NSEC_PER_SEC;
> >
> > The issue is that timestamping is in the fast path and that 64 bit divide is slow.
> > Looking at other alternatives.
>
> Then perhaps we can keep the division optimization and just get rid of
> the overflow check, relying on the change to multiply by NSEC_PER_SEC
> after the division.
>
> With the below change only the first packet is from 2257 while all
> subsequent packets are fine. But if I keep the overflow check and only
> change to multiply after the division, then all packets are shown from
> 2257.
>
> [admin@Rocky8 dpdk]$ git diff lib/pcapng/rte_pcapng.c
> diff --git a/lib/pcapng/rte_pcapng.c b/lib/pcapng/rte_pcapng.c
> index 80d08e1..fa545cd 100644
> --- a/lib/pcapng/rte_pcapng.c
> +++ b/lib/pcapng/rte_pcapng.c
> @@ -79,7 +79,7 @@ static uint64_t pcapng_tsc_to_ns(uint64_t cycles)
>          * Currently all TSCs operate below 5GHz.
>          */
>         delta = cycles - pcapng_time.cycles;
> -       if (unlikely(delta >= pcapng_time.tsc_hz)) {
> +       if (0 && unlikely(delta >= pcapng_time.tsc_hz)) {
>                 if (likely(delta < pcapng_time.tsc_hz * 2)) {
>                         delta -= pcapng_time.tsc_hz;
>                         pcapng_time.cycles += pcapng_time.tsc_hz;
> @@ -92,8 +92,9 @@ static uint64_t pcapng_tsc_to_ns(uint64_t cycles)
>                 }
>         }
>
> -       return pcapng_time.ns + rte_reciprocal_divide_u64(delta * NSEC_PER_SEC,
> -
> &pcapng_time.tsc_hz_inverse);
> +       return pcapng_time.ns + rte_reciprocal_divide_u64(delta,
> +
> &pcapng_time.tsc_hz_inverse) * NSEC_PER_SEC;
>  }