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 31455A034D; Wed, 5 Jan 2022 18:58:37 +0100 (CET) Received: from [217.70.189.124] (localhost [127.0.0.1]) by mails.dpdk.org (Postfix) with ESMTP id EAB2940E03; Wed, 5 Jan 2022 18:58:36 +0100 (CET) Received: from mail-pf1-f174.google.com (mail-pf1-f174.google.com [209.85.210.174]) by mails.dpdk.org (Postfix) with ESMTP id 45606406B4 for ; Wed, 5 Jan 2022 18:58:35 +0100 (CET) Received: by mail-pf1-f174.google.com with SMTP id m1so31930pfk.8 for ; Wed, 05 Jan 2022 09:58:35 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=networkplumber-org.20210112.gappssmtp.com; s=20210112; h=date:from:to:cc:subject:message-id:in-reply-to:references :mime-version:content-transfer-encoding; bh=/uzWF4IV2ISnrV9NAAvUxcRrP9d5iV0F0m6GY3gqnGY=; b=CupbnvyuiGltJHRqbfX0UZaxjGGYah0F4QEpShqbkui89RZWUOXyP90651onD5zgCF w2ttJsPQt4QPomCMD+vskU731sE9sxuK4W+2lpEFNMeUZmEgQbD95YKJ7EdwUI0qmIT4 G9vzTtZ+iuE1T88lrNaRml/BsO52vN6hvi8MZ9oq+LuV81+QuPDJwnzJ3jFNxQkpXmK4 3usky1K2tAelL4d3olgh+D63IKDlKgkN+u0lzcXBqMhLraAGYAcuq3mRcvQlwhoFRAxQ vQn7+NhzCSQkJEtMby2guvCkkvYyCsw7hKANfoxlJ19L7XNkRJZPp9wc+UmOOFyU/oVx sjNQ== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=x-gm-message-state:date:from:to:cc:subject:message-id:in-reply-to :references:mime-version:content-transfer-encoding; bh=/uzWF4IV2ISnrV9NAAvUxcRrP9d5iV0F0m6GY3gqnGY=; b=jtD+YKuK5kNSIBYSisupPIQt3hSPFY8Rng+Ixd3x/F8erHQCnkmDELTn8P/5CSfkoY xDRbTstkVhJ5BmZm5JKPjTAnJEmYdjiVIUHb9sFkSdIsjOIgZ5bhGDjMXzN7gkOOuqeM HK/AVad58z9M88cJOQLsJmUlq4PfEQc1DZOd12Xvy0RjaxpqllxvpZhKLsm+vgJ1Up1p OY5cUAdM+Wz+ODPgSg4Z+QB2mhOIGqdiyWDp+ADDBkuMnn0okmjfZutKtShw1zBWtvQk XbcQi5VwM34gidVx1zdK4ZR4TVz+zk4vSqI4NLYnW0JyH/qn12jjcCY6Zpxg778igqpn luPg== X-Gm-Message-State: AOAM5301mUQmiGaoYHn8bvmlkKQn6rPcvbFDj636oCkXnSGPF7+5zadK cwDX7wGD1M7sjoIX4o6GPam/vHQZUGg2VQ== X-Google-Smtp-Source: ABdhPJyhOKIAbwNjtlH4HXfNP1tEkFfJGm+rfH/l93PVCL+m1l/b48PDixzj4f2kuzfBTuLg+OCNaA== X-Received: by 2002:a63:1505:: with SMTP id v5mr49461481pgl.549.1641405514352; Wed, 05 Jan 2022 09:58:34 -0800 (PST) Received: from hermes.local (204-195-112-199.wavecable.com. [204.195.112.199]) by smtp.gmail.com with ESMTPSA id t27sm23010974pgm.52.2022.01.05.09.58.33 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 05 Jan 2022 09:58:34 -0800 (PST) Date: Wed, 5 Jan 2022 09:58:31 -0800 From: Stephen Hemminger To: Soumya Muralidhar Cc: "dev@dpdk.org" Subject: Re: Add timestamp to dpdk.log Message-ID: <20220105095831.20e74174@hermes.local> In-Reply-To: <892917C6-9F3F-4AF0-9429-A4AC19DC47BC@gigamon.com> References: <25E66ADE-793E-4C7E-A70F-29EFD2AE7CEA@gigamon.com> <20220105081719.10ede5a5@hermes.local> <892917C6-9F3F-4AF0-9429-A4AC19DC47BC@gigamon.com> MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable 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 On Wed, 5 Jan 2022 17:42:49 +0000 Soumya Muralidhar wrote: > Hi Stephen, >=20 > Thanks for getting back. But I am looking at storing logs with timestamps= in a file, basically something similar to syslog. Could you help me with t= hat ? >=20 > Regards, > Soumya >=20 > =EF=BB=BFOn 1/5/22, 8:17 AM, "Stephen Hemminger" wrote: >=20 > WARNING: This email originated from outside of Gigamon. Use caution w= ith any links or attachments. >=20 >=20 > Your message is garbaled with lots of bogus URL's. Please avoid HTML = mail > or weird links. >=20 > I use this. There was a more general version submitted as a patch to > DPDK but no one seemed interested. The reason for redirecting stdout > is that are libraries we use that print to stdout and want to get tim= estamps > from them if debugging startup issues. >=20 >=20 > /* > * Sample of redirecting DPDK log stream. > * > * If program is run for debugging then stdout will be a console and > * put messages onto console stream with timestamps. Otherwise, just > * put message onto stderr which systemd journal handles. No need for > * syslog because that causes duplicate messages. > */ >=20 > static struct timespec log_t0; /* Start program in monotonic time */ >=20 > /* > * Write message to standard output with timestamp. > * Use writev() so that timestamp and message do not get interleaved. > */ > static ssize_t > dpdk_log_tty_write(__rte_unused void *ctx, const char *buf, size_t si= ze) > { > struct timespec ts; > struct iovec iov[2]; > char tbuf[64]; >=20 > /* format up monotonic timestamp */ > clock_gettime(CLOCK_MONOTONIC, &ts); >=20 > ts.tv_sec -=3D log_t0.tv_sec; > ts.tv_nsec -=3D log_t0.tv_nsec; > if (ts.tv_nsec < 0) { > --ts.tv_sec; > ts.tv_nsec +=3D NS_PER_S; > } >=20 > iov[0].iov_base =3D tbuf; > iov[0].iov_len =3D snprintf(tbuf, sizeof(tbuf), "[%8lu.%06lu= ] ", > ts.tv_sec, ts.tv_nsec / 1000u); >=20 > /* extra cast is workaround to remove const qualifier */ > iov[1].iov_base =3D (void *)(uintptr_t)buf; > iov[1].iov_len =3D size; >=20 > return writev(STDOUT_FILENO, iov, 2); > } >=20 > static cookie_io_functions_t dpdk_log_tty_func =3D { > .write =3D dpdk_log_tty_write, > }; >=20 > /* > * Print message to stderr with priority format so that > * Systemd journal can handle it. Alternative would be > * to use syslog or use sd_journal; but less is more. > */ > static ssize_t > dpdk_log_write(__rte_unused void *ctx, const char *buf, size_t size) > { > /* Syslog error levels are from 0 to 7, DPDK uses 1 to 8 */ > int priority =3D rte_log_cur_msg_loglevel() - 1; >=20 > fprintf(stderr, "<%i>%.*s\n", priority, (int)size, buf); > return size; > } >=20 > static cookie_io_functions_t dpdk_log_func =3D { > .write =3D dpdk_log_write, > }; >=20 > /* > * Override default DPDK logging which duplicates messages > * to both stderr and syslog. > */ > static void log_init(void) > { > backplane_logtype =3D rte_log_register("backplane"); > if (backplane_logtype >=3D 0) > rte_log_set_level(backplane_logtype, RTE_LOG_INFO); >=20 > if (isatty(STDOUT_FILENO)) { > clock_gettime(CLOCK_MONOTONIC, &log_t0); >=20 > stdout =3D fopencookie(NULL, "w+", dpdk_log_tty_func); > setlinebuf(stdout); > rte_openlog_stream(stdout); > } else { > FILE *jf; >=20 > jf =3D fopencookie(NULL, "w+", dpdk_log_func); > rte_openlog_stream(jf); > } > } >=20 > /* Put DPDK log back onto stderr */ > static void log_uninit(void) > { > FILE *logf; >=20 > logf =3D rte_log_get_stream(); > if (logf !=3D stderr) { > rte_openlog_stream(stderr); > fclose(logf); > } > } >=20 > This message may contain confidential and privileged information. If it h= as been sent to you in error, please reply to advise the sender of the erro= r and then immediately delete it. If you are not the intended recipient, do= not read, copy, disclose or otherwise use this message. The sender disclai= ms any liability for such unauthorized use. NOTE that all incoming emails s= ent to Gigamon email accounts will be archived and may be scanned by us and= /or by external service providers to detect and prevent threats to our syst= ems, investigate illegal or inappropriate behavior, and/or eliminate unsoli= cited promotional emails (=E2=80=9Cspam=E2=80=9D). Just use my example and make code like dpdk_tty_log_write that does writev = to your file.