From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mails.dpdk.org (mails.dpdk.org [217.70.189.124]) by inbox.dpdk.org (Postfix) with ESMTP id A3FC342601 for ; Thu, 21 Sep 2023 04:09:56 +0200 (CEST) Received: from mails.dpdk.org (localhost [127.0.0.1]) by mails.dpdk.org (Postfix) with ESMTP id 144094026D; Thu, 21 Sep 2023 04:09:56 +0200 (CEST) Received: from mail-yb1-f177.google.com (mail-yb1-f177.google.com [209.85.219.177]) by mails.dpdk.org (Postfix) with ESMTP id E37CB4014F for ; Thu, 21 Sep 2023 04:09:53 +0200 (CEST) Received: by mail-yb1-f177.google.com with SMTP id 3f1490d57ef6-d8162698f0dso645280276.0 for ; Wed, 20 Sep 2023 19:09:53 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=networkplumber-org.20230601.gappssmtp.com; s=20230601; t=1695262193; x=1695866993; darn=dpdk.org; h=content-transfer-encoding:mime-version:references:in-reply-to :message-id:subject:cc:to:from:date:from:to:cc:subject:date :message-id:reply-to; bh=cBdgLeGsYyX4VofYkyewp0LJx0+XPEoHC+XqUFNSjBA=; b=AwMMgSmR4atO4a+xRH9uL2b5ciVNnVEYmeLgZj//NEBPfWOlk2U/IeW8gdj3oWKPht lk68UkLX5zNbQsNMB1X+peGIfki3v6oVkDhzif5FK8zDQ2NXvAh+OJrfvAy6kiNhQF5U LQRD4/wyFbrEk/Z/WT5zFYy9iAEiFVlJ6HhlMSvGC3sqm3t2BgIFEg3QJlRi2ut3skhp T0fWvFGaQsNp+tAFPeZRBF/V77JbAE62YqGrdsv5DAHYIPlp5ntUgf13RHJJ7VDfNno8 6Gx+KDWyDPGvxFxLfmV2uCnUb03/j0oiQDyeHtwynYMyaA3KVC0t8tUIS/2ASaZQasEK 0Edw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1695262193; x=1695866993; h=content-transfer-encoding:mime-version:references:in-reply-to :message-id:subject:cc:to:from:date:x-gm-message-state:from:to:cc :subject:date:message-id:reply-to; bh=cBdgLeGsYyX4VofYkyewp0LJx0+XPEoHC+XqUFNSjBA=; b=VRNLyAU4twJjivMmOnhyDDRRL7rczvzzzPTlUW1ze9zcfHq0xJ3yfFyz940d9I3yrG wPYCBkXeYa+IZac5TA8D3UiRKPv0XKXC7nntUT/f9XQmAVgLjrBSjF0o4AM5REt4Wmlx jU6abYXhA4TqF3gyb8VB4o+k2VbGVLav0H29R/OWZH5q1MjvheheH/gNVURXDtxy3YZP oRie2F3aM+ZqAurtDQvDe4d3H8oMmU1xG4wgrAsHI7P35/0g0sCipekVqqR9vARkZTln tkZADXtJCcfV5tK6LuNkHng/dOONSEB8sAm1wUEYgiMVCW6+HwH8PWj+SnsYj0F5EZEz oDVw== X-Gm-Message-State: AOJu0Yx9e0vO/mEkfZwv8jwRecnLwcl7pkFkFaWOcFK3mWfHF07TzPt8 03KiVYiwZ7rkea80DVa+wlY5iw== X-Google-Smtp-Source: AGHT+IH9PhdaCCPIsF1maHIliOrqWw37cFhp5LQegLoqolqGaQRcAdUooFl3m4HVJCLO8P/eE4NwHg== X-Received: by 2002:a25:ad8d:0:b0:d81:97c:c01c with SMTP id z13-20020a25ad8d000000b00d81097cc01cmr4841236ybi.23.1695262192960; Wed, 20 Sep 2023 19:09:52 -0700 (PDT) Received: from hermes.local (204-195-112-131.wavecable.com. [204.195.112.131]) by smtp.gmail.com with ESMTPSA id v3-20020a655c43000000b005782ad723casm118903pgr.27.2023.09.20.19.09.52 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 20 Sep 2023 19:09:52 -0700 (PDT) Date: Wed, 20 Sep 2023 19:09:50 -0700 From: Stephen Hemminger To: Isaac Boukris Cc: users@dpdk.org Subject: Re: dumpcap: timestamp is years ahead when in pcapng format Message-ID: <20230920190950.5acdae45@hermes.local> In-Reply-To: References: <20230919110009.29e90615@hermes.local> MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable X-BeenThere: users@dpdk.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: DPDK usage discussions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: users-bounces@dpdk.org On Wed, 20 Sep 2023 22:55:21 +0300 Isaac Boukris wrote: > I found a way to get a better resolution; at init we set > 'pcapng_time.tsc_hz=3Drte_get_tsc_hz()/NSEC_PER_SEC' this way we keep > the number of cycles in a nano-second, then at run time we just need > to divide delta by this number (with no need to multiply by > NSEC_PER_SEC). >=20 > The problem is I guess, that on slow systems we'll end up with > tsc_hz=3D0? Perhaps we'd need to drop to ms resolution in such a case. >=20 > With the attach patch I get: >=20 > 2023-09-20 10:22:13.579219 IP Rocky8 > A: ICMP echo request, id 13, > seq 63, length 64 > 2023-09-20 10:22:13.580582 IP A > Rocky8: ICMP echo reply, id 13, seq > 63, length 64 3 > 2023-09-20 10:22:14.745176 IP Rocky8 > A: ICMP echo request, id 13, > seq 64, length 64 > 2023-09-20 10:22:14.746206 IP ... >=20 > On Wed, Sep 20, 2023 at 9:53=E2=80=AFPM Isaac Boukris wrote: > > > > 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=E2=80=AFPM Isaac Boukris wrote: > > > > > > On Tue, Sep 19, 2023 at 9:00=E2=80=AFPM Stephen Hemminger > > > wrote: > > > > > > > > On Tue, 19 Sep 2023 19:35:55 +0300 > > > > Isaac Boukris 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: 319= 75 > > > > > NXDomain 0/0/0 (46) = 10 > > > > > 2023-09-19 08:05:21.577497 ARP, Request who-has _gateway tell Roc= ky8, > > > > > 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 dro= pped > > > > > 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 =3D cycles - pcapng_time.cycles; > > > - if (unlikely(delta >=3D pcapng_time.tsc_hz)) { > > > + if (0 && unlikely(delta >=3D pcapng_time.tsc_hz)) { > > > if (likely(delta < pcapng_time.tsc_hz * 2)) { > > > delta -=3D pcapng_time.tsc_hz; > > > pcapng_time.cycles +=3D 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 * NSE= C_PER_SEC, > > > - > > > &pcapng_time.tsc_hz_inverse); > > > + return pcapng_time.ns + rte_reciprocal_divide_u64(delta, > > > + > > > &pcapng_time.tsc_hz_inverse) * NSEC_PER_SEC; > > > } This is less accurate. The TSC (CPU clock frequency) is not necessarily an even multiple of nanoseconds. If you want to send patches please follow the contributing guidelines and run checkpatch on them.