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 2432143CF8; Tue, 19 Mar 2024 08:37:34 +0100 (CET) Received: from mails.dpdk.org (localhost [127.0.0.1]) by mails.dpdk.org (Postfix) with ESMTP id C31DB40298; Tue, 19 Mar 2024 08:37:33 +0100 (CET) Received: from dkmailrelay1.smartsharesystems.com (smartserver.smartsharesystems.com [77.243.40.215]) by mails.dpdk.org (Postfix) with ESMTP id 3B15840289 for ; Tue, 19 Mar 2024 08:37:32 +0100 (CET) Received: from smartserver.smartsharesystems.com (smartserver.smartsharesys.local [192.168.4.10]) by dkmailrelay1.smartsharesystems.com (Postfix) with ESMTP id 0F65720CA1; Tue, 19 Mar 2024 08:37:32 +0100 (CET) Content-class: urn:content-classes:message MIME-Version: 1.0 Content-Type: text/plain; charset="iso-8859-1" Content-Transfer-Encoding: quoted-printable Subject: RE: [PATCH v9 5/5] eal: add option to put timestamp on console output Date: Tue, 19 Mar 2024 08:37:30 +0100 X-MimeOLE: Produced By Microsoft Exchange V6.5 Message-ID: <98CBD80474FA8B44BF855DF32C47DC35E9F2FE@smartserver.smartshare.dk> In-Reply-To: <20240318220432.7486-6-stephen@networkplumber.org> X-MS-Has-Attach: X-MS-TNEF-Correlator: Thread-Topic: [PATCH v9 5/5] eal: add option to put timestamp on console output Thread-Index: Adp5gF5j5sGFT6SlT2SMOWTzZ7mUEQATux7A References: <20200814173441.23086-1-stephen@networkplumber.org> <20240318220432.7486-1-stephen@networkplumber.org> <20240318220432.7486-6-stephen@networkplumber.org> From: =?iso-8859-1?Q?Morten_Br=F8rup?= To: "Stephen Hemminger" , X-BeenThere: dev@dpdk.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: DPDK patches and discussions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: dev-bounces@dpdk.org > From: Stephen Hemminger [mailto:stephen@networkplumber.org] > Sent: Monday, 18 March 2024 23.03 >=20 > When debugging driver or startup issues, it is useful to have > a timestamp on each message printed. The messages in syslog > already have a timestamp, but often syslog is not available > during testing. The timestamp format is chosen to look > like the default Linux dmesg timestamp. >=20 > The first few lines are not timestamped because the flag is stored > in internal configuration which is stored in shared memory > which is not setup up until a little later in startup process. >=20 > This logging skips the unnecessary step of going through stdio, > which makes it more robust against being called in interrupt > handlers etc. >=20 > Example: > $ dpdk-testpmd --log-timestamp -- -i > EAL: Detected CPU lcores: 16 > EAL: Detected NUMA nodes: 1 > EAL: Detected static linkage of DPDK > EAL: Multi-process socket /var/run/dpdk/rte/mp_socket > EAL: Selected IOVA mode 'VA' > [ 0.112264] testpmd: No probed ethernet devices > Interactive-mode selected > [ 0.184573] testpmd: create a new mbuf pool : = n=3D163456, > size=3D2176, socket=3D0 > [ 0.184612] testpmd: preferred mempool ops selected: ring_mp_mc >=20 > Signed-off-by: Stephen Hemminger > --- [...] > static ssize_t > console_log_write(__rte_unused void *c, const char *buf, size_t size) > { > + struct timespec ts; > ssize_t ret; >=20 > - /* write on stderr */ > - ret =3D fwrite(buf, 1, size, stderr); > + if (timestamp_enabled) { > + clock_gettime(CLOCK_MONOTONIC, &ts); > + ts.tv_sec -=3D log_started.tv_sec; > + ts.tv_nsec -=3D log_started.tv_nsec; Please log the absolute CLOCK_MONOTONIC instead of subtracting = log_started, so timestamps can be easily compared with timestamps from = other processes. > + if (ts.tv_nsec < 0) { > + --ts.tv_sec; > + ts.tv_nsec +=3D 1000000000ul; > + } > + > + ret =3D fprintf(stderr, "[%8lu.%06lu] %.*s", > + ts.tv_sec, ts.tv_nsec / 1000u, > + (int) size, buf); With the above change, For the series, Acked-by: Morten Br=F8rup