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 0B8E1A034E; Wed, 5 Jan 2022 17:17:25 +0100 (CET) Received: from [217.70.189.124] (localhost [127.0.0.1]) by mails.dpdk.org (Postfix) with ESMTP id 872AC406B4; Wed, 5 Jan 2022 17:17:24 +0100 (CET) Received: from mail-pj1-f52.google.com (mail-pj1-f52.google.com [209.85.216.52]) by mails.dpdk.org (Postfix) with ESMTP id CDDC940685 for ; Wed, 5 Jan 2022 17:17:22 +0100 (CET) Received: by mail-pj1-f52.google.com with SMTP id c9-20020a17090a1d0900b001b2b54bd6c5so4835669pjd.1 for ; Wed, 05 Jan 2022 08:17:22 -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=rJGXvpUkqAdTcflb+C1egKQDcUeXE5qCXGYfWLNT97w=; b=i+taF42QOyuhoHr8dQI6YxcMtuEoH297dIpbEdjgidPwieP23kLpbagurtKoEzvDIY 0xsMutyWB03I4R9QVkp+kONWk79iKYNML2p/MRz2oUsQB3J45u8GabXwyNcZaSaz+vS+ jLnw66aBdXug8KKklSrDbe/+dwL9RSzwarXbK9qx3jAFZLkpHoUq4Lfpo6jEwF+3JW4u 1ZCNIdVkcE426Rx0Y+8Sb9ggLfMYQNPzVggM1vJ7ZI/4Axa0Sy70vjuuKXsdaiTJ8pz6 MZ2/4uUUBFrLO818I9dCP2ZCKyQ5lUCY1qORq5yHSwTvilXg2l3ccKRmS9zB38xhAK+I 1ctA== 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=rJGXvpUkqAdTcflb+C1egKQDcUeXE5qCXGYfWLNT97w=; b=dROSQ8Cy+r84/AveuKv8NLXgQhusk0LOLjT+bCsrOV1u64GWbEPfe+OjoDODCYLs3u /XEI731v2MSjQZM1CQIHF2SQWoQq88/sMY6mPw0NbRISIq2TfTtsFCPGaMqNAZ/mPJcD 2tDMAqNbIlrqymFTx5XbnBc0PQBHY5f2y2zWLFm+jj8gHnxayjr9bKvP7LAtaIeXmbFS LhVd4ahBuCxsy8wB0RWNBOozZGqflfP1w/vPUq46TEbN3tY0oCvGsAE3g08ZQca24go8 tGpPOl2ttQSf1D10HHzUzWNdihYJPWcRPLxxUmX17mmzYqTbpqwoK9heVVimrnhk/Q9z 4RWw== X-Gm-Message-State: AOAM531Om3iZ48A2a582PLgVnnxLhGcwcGM8JMFJvy5MSkWiblfoRdth c1w9TH6bWEOAAQJ9Q5e9K9Xcfw== X-Google-Smtp-Source: ABdhPJxaNn8Xkmux2j5IjgVH068c6ZZrLHZa+MOLmaYZM6KoCIeMxUVP1YFUjiqefeLZ3PbVQMbiTQ== X-Received: by 2002:a17:90b:4c8d:: with SMTP id my13mr4936616pjb.163.1641399441700; Wed, 05 Jan 2022 08:17:21 -0800 (PST) Received: from hermes.local (204-195-112-199.wavecable.com. [204.195.112.199]) by smtp.gmail.com with ESMTPSA id s18sm1897326pjq.4.2022.01.05.08.17.21 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 05 Jan 2022 08:17:21 -0800 (PST) Date: Wed, 5 Jan 2022 08:17:19 -0800 From: Stephen Hemminger To: Soumya Muralidhar Cc: "dev@dpdk.org" Subject: Re: Add timestamp to dpdk.log Message-ID: <20220105081719.10ede5a5@hermes.local> In-Reply-To: <25E66ADE-793E-4C7E-A70F-29EFD2AE7CEA@gigamon.com> References: <25E66ADE-793E-4C7E-A70F-29EFD2AE7CEA@gigamon.com> MIME-Version: 1.0 Content-Type: text/plain; charset=US-ASCII Content-Transfer-Encoding: 7bit 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 Your message is garbaled with lots of bogus URL's. Please avoid HTML mail or weird links. 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 timestamps from them if debugging startup issues. /* * 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. */ static struct timespec log_t0; /* Start program in monotonic time */ /* * 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 size) { struct timespec ts; struct iovec iov[2]; char tbuf[64]; /* format up monotonic timestamp */ clock_gettime(CLOCK_MONOTONIC, &ts); ts.tv_sec -= log_t0.tv_sec; ts.tv_nsec -= log_t0.tv_nsec; if (ts.tv_nsec < 0) { --ts.tv_sec; ts.tv_nsec += NS_PER_S; } iov[0].iov_base = tbuf; iov[0].iov_len = snprintf(tbuf, sizeof(tbuf), "[%8lu.%06lu] ", ts.tv_sec, ts.tv_nsec / 1000u); /* extra cast is workaround to remove const qualifier */ iov[1].iov_base = (void *)(uintptr_t)buf; iov[1].iov_len = size; return writev(STDOUT_FILENO, iov, 2); } static cookie_io_functions_t dpdk_log_tty_func = { .write = dpdk_log_tty_write, }; /* * 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 = rte_log_cur_msg_loglevel() - 1; fprintf(stderr, "<%i>%.*s\n", priority, (int)size, buf); return size; } static cookie_io_functions_t dpdk_log_func = { .write = dpdk_log_write, }; /* * Override default DPDK logging which duplicates messages * to both stderr and syslog. */ static void log_init(void) { backplane_logtype = rte_log_register("backplane"); if (backplane_logtype >= 0) rte_log_set_level(backplane_logtype, RTE_LOG_INFO); if (isatty(STDOUT_FILENO)) { clock_gettime(CLOCK_MONOTONIC, &log_t0); stdout = fopencookie(NULL, "w+", dpdk_log_tty_func); setlinebuf(stdout); rte_openlog_stream(stdout); } else { FILE *jf; jf = fopencookie(NULL, "w+", dpdk_log_func); rte_openlog_stream(jf); } } /* Put DPDK log back onto stderr */ static void log_uninit(void) { FILE *logf; logf = rte_log_get_stream(); if (logf != stderr) { rte_openlog_stream(stderr); fclose(logf); } }