Patch Detail
get:
Show a patch.
patch:
Update a patch.
put:
Update a patch.
GET /api/patches/129083/?format=api
{ "id": 129083, "url": "http://patchwork.dpdk.org/api/patches/129083/?format=api", "web_url": "http://patchwork.dpdk.org/project/dpdk/patch/20230628175827.471909-7-stephen@networkplumber.org/", "project": { "id": 1, "url": "http://patchwork.dpdk.org/api/projects/1/?format=api", "name": "DPDK", "link_name": "dpdk", "list_id": "dev.dpdk.org", "list_email": "dev@dpdk.org", "web_url": "http://core.dpdk.org", "scm_url": "git://dpdk.org/dpdk", "webscm_url": "http://git.dpdk.org/dpdk", "list_archive_url": "https://inbox.dpdk.org/dev", "list_archive_url_format": "https://inbox.dpdk.org/dev/{}", "commit_url_format": "" }, "msgid": "<20230628175827.471909-7-stephen@networkplumber.org>", "list_archive_url": "https://inbox.dpdk.org/dev/20230628175827.471909-7-stephen@networkplumber.org", "date": "2023-06-28T17:58:27", "name": "[v5,6/6] eal: add option to put timestamp on console output", "commit_ref": null, "pull_url": null, "state": "superseded", "archived": true, "hash": "28ae29fe1487d78e0c517829da84c7bcf6f49468", "submitter": { "id": 27, "url": "http://patchwork.dpdk.org/api/people/27/?format=api", "name": "Stephen Hemminger", "email": "stephen@networkplumber.org" }, "delegate": { "id": 1, "url": "http://patchwork.dpdk.org/api/users/1/?format=api", "username": "tmonjalo", "first_name": "Thomas", "last_name": "Monjalon", "email": "thomas@monjalon.net" }, "mbox": "http://patchwork.dpdk.org/project/dpdk/patch/20230628175827.471909-7-stephen@networkplumber.org/mbox/", "series": [ { "id": 28695, "url": "http://patchwork.dpdk.org/api/series/28695/?format=api", "web_url": "http://patchwork.dpdk.org/project/dpdk/list/?series=28695", "date": "2023-06-28T17:58:21", "name": "Logging related patches", "version": 5, "mbox": "http://patchwork.dpdk.org/series/28695/mbox/" } ], "comments": "http://patchwork.dpdk.org/api/patches/129083/comments/", "check": "fail", "checks": "http://patchwork.dpdk.org/api/patches/129083/checks/", "tags": {}, "related": [], "headers": { "Return-Path": "<dev-bounces@dpdk.org>", "X-Original-To": "patchwork@inbox.dpdk.org", "Delivered-To": "patchwork@inbox.dpdk.org", "Received": [ "from mails.dpdk.org (mails.dpdk.org [217.70.189.124])\n\tby inbox.dpdk.org (Postfix) with ESMTP id 29F3942D82;\n\tWed, 28 Jun 2023 19:59:12 +0200 (CEST)", "from mails.dpdk.org (localhost [127.0.0.1])\n\tby mails.dpdk.org (Postfix) with ESMTP id 63C3C42D35;\n\tWed, 28 Jun 2023 19:58:42 +0200 (CEST)", "from mail-pl1-f169.google.com (mail-pl1-f169.google.com\n [209.85.214.169])\n by mails.dpdk.org (Postfix) with ESMTP id 0786942D10\n for <dev@dpdk.org>; Wed, 28 Jun 2023 19:58:39 +0200 (CEST)", "by mail-pl1-f169.google.com with SMTP id\n d9443c01a7336-1b7fb1a82c4so1528075ad.1\n for <dev@dpdk.org>; Wed, 28 Jun 2023 10:58:38 -0700 (PDT)", "from hermes.local (204-195-120-218.wavecable.com. [204.195.120.218])\n by smtp.gmail.com with ESMTPSA id\n g11-20020a170902868b00b001b80d399730sm5047875plo.242.2023.06.28.10.58.36\n (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256);\n Wed, 28 Jun 2023 10:58:36 -0700 (PDT)" ], "DKIM-Signature": "v=1; a=rsa-sha256; c=relaxed/relaxed;\n d=networkplumber-org.20221208.gappssmtp.com; s=20221208; t=1687975118;\n x=1690567118;\n h=content-transfer-encoding:mime-version:references:in-reply-to\n :message-id:date:subject:cc:to:from:from:to:cc:subject:date\n :message-id:reply-to;\n bh=RY8J9r9mCUW4V1UoowqIgtEXc5CryfGDGywTRhgsi5o=;\n b=wNhrZuwMHo1dNozCbvktWIt3FLgGAISvCBBetJUjYajRPEtsvRelf1tEGYwTuuBrAe\n L9ZuVoVuLZqbUk/JN0//r/kgEj4KUzK5FpeNK1muG1xPjL75uo+NqWgnxObQuXBC87UI\n hBy8OFmO1I+rkqX6oFJJGmuFD1D3MpfllWnLiCupxMDiTsQQ0lI46dRirdHMauwwMuCt\n MfqhqUBAuKHXKieySoHIkbGb24018BSOdYNG4PqAzuwSny7QJEeoQ69Lq09kCBa4NJAm\n JC58RkQa+hWoG8ZEr/pySWUskFZ54AvCFPaImuKpecfJMwa/UXyBxk6ittYLWY/gQuJE\n qUag==", "X-Google-DKIM-Signature": "v=1; a=rsa-sha256; c=relaxed/relaxed;\n d=1e100.net; s=20221208; t=1687975118; x=1690567118;\n h=content-transfer-encoding:mime-version:references:in-reply-to\n :message-id:date:subject:cc:to:from:x-gm-message-state:from:to:cc\n :subject:date:message-id:reply-to;\n bh=RY8J9r9mCUW4V1UoowqIgtEXc5CryfGDGywTRhgsi5o=;\n b=ESfR4EDSKMXzAE6i5mSDHz/zWM8GLtN/pyHvrvS7r2aY81InRxBOTSVo2oyiTVxLYy\n Smvb5FlQf5tLlLLe0KAFiFeDBOn+SIiuZsuGEqP8OT/05ecoZma4EJj9kh0wTrxZYXLn\n 4i5JpUj9w50LbiwWoxburrhPjARaXLqWEPXXRCyciD8Dbt5dylT/EMDn14l320ZwYWRQ\n sy78MGAiXAiLmRPef2Dx5JjbXd51mZOe8ilhtp1vPvKCvYVHxVmfI5mqdEtBXxL+Cj78\n fKijm+Ek/D/KmI3OVBmQ/mVCg8j/4YiSOcyaCqNym2X+SVJqmagKAiPeXmSibzcggeK9\n yyoQ==", "X-Gm-Message-State": "AC+VfDyIbD+7tiXW5hX6PZW2E2LLSCB+46/4gr5HS0kgFMABaVl7Y+Tn\n u9PtxmupIBkNaw/1DGUC47oDeeTsaFDmRnpieXmaRg==", "X-Google-Smtp-Source": "\n ACHHUZ5FkNhLpPZxei2PhKQqZ2R+JZyIKJ/js4KCib4I3qJnTb18a3bYs4Rmc6FG2aanVBaT7XBtLg==", "X-Received": "by 2002:a17:903:41c5:b0:1b6:8863:8c9f with SMTP id\n u5-20020a17090341c500b001b688638c9fmr13009463ple.6.1687975117876;\n Wed, 28 Jun 2023 10:58:37 -0700 (PDT)", "From": "Stephen Hemminger <stephen@networkplumber.org>", "To": "dev@dpdk.org", "Cc": "Stephen Hemminger <stephen@networkplumber.org>,\n Bruce Richardson <bruce.richardson@intel.com>,\n Anatoly Burakov <anatoly.burakov@intel.com>", "Subject": "[PATCH v5 6/6] eal: add option to put timestamp on console output", "Date": "Wed, 28 Jun 2023 10:58:27 -0700", "Message-Id": "<20230628175827.471909-7-stephen@networkplumber.org>", "X-Mailer": "git-send-email 2.39.2", "In-Reply-To": "<20230628175827.471909-1-stephen@networkplumber.org>", "References": "<20200814173441.23086-1-stephen@networkplumber.org>\n <20230628175827.471909-1-stephen@networkplumber.org>", "MIME-Version": "1.0", "Content-Transfer-Encoding": "8bit", "X-BeenThere": "dev@dpdk.org", "X-Mailman-Version": "2.1.29", "Precedence": "list", "List-Id": "DPDK patches and discussions <dev.dpdk.org>", "List-Unsubscribe": "<https://mails.dpdk.org/options/dev>,\n <mailto:dev-request@dpdk.org?subject=unsubscribe>", "List-Archive": "<http://mails.dpdk.org/archives/dev/>", "List-Post": "<mailto:dev@dpdk.org>", "List-Help": "<mailto:dev-request@dpdk.org?subject=help>", "List-Subscribe": "<https://mails.dpdk.org/listinfo/dev>,\n <mailto:dev-request@dpdk.org?subject=subscribe>", "Errors-To": "dev-bounces@dpdk.org" }, "content": "When debugging driver or startup issues, it is useful to have\na timestamp on each message printed. The messages in syslog\nalready have a timestamp, but often syslog is not available\nduring testing. The timestamp format is chosen to look\nlike the default Linux dmesg timestamp.\n\nThe first few lines are not timestamped because the flag is stored\nin internal configuration which is stored in shared memory\nwhich is not setup up until a little later in startup process.\n\nExample:\n$ dpdk-testpmd --log-timestamp -- -i\nEAL: Detected CPU lcores: 16\nEAL: Detected NUMA nodes: 1\nEAL: Detected static linkage of DPDK\nEAL: Multi-process socket /var/run/dpdk/rte/mp_socket\nEAL: Selected IOVA mode 'VA'\n[ 0.112264] testpmd: No probed ethernet devices\nInteractive-mode selected\n[ 0.184573] testpmd: create a new mbuf pool <mb_pool_0>: n=163456, size=2176, socket=0\n[ 0.184612] testpmd: preferred mempool ops selected: ring_mp_mc\n\nSigned-off-by: Stephen Hemminger <stephen@networkplumber.org>\n---\n .../freebsd_gsg/freebsd_eal_parameters.rst | 5 +++\n doc/guides/linux_gsg/linux_eal_parameters.rst | 5 +++\n lib/eal/common/eal_common_options.c | 6 +++\n lib/eal/common/eal_internal_cfg.h | 3 ++\n lib/eal/common/eal_options.h | 2 +\n lib/eal/freebsd/eal.c | 4 +-\n lib/eal/linux/eal.c | 4 +-\n lib/eal/unix/eal_log.c | 44 +++++++++++++++++--\n 8 files changed, 67 insertions(+), 6 deletions(-)", "diff": "diff --git a/doc/guides/freebsd_gsg/freebsd_eal_parameters.rst b/doc/guides/freebsd_gsg/freebsd_eal_parameters.rst\nindex 9270d9fa3bfc..99cff10e963c 100644\n--- a/doc/guides/freebsd_gsg/freebsd_eal_parameters.rst\n+++ b/doc/guides/freebsd_gsg/freebsd_eal_parameters.rst\n@@ -45,3 +45,8 @@ Other options\n local5\n local6\n local7\n+\n+* ``--log-timestamp``\n+\n+ Add a timestamp of seconds and microseconds to each log message\n+ written to standard output.\ndiff --git a/doc/guides/linux_gsg/linux_eal_parameters.rst b/doc/guides/linux_gsg/linux_eal_parameters.rst\nindex ea8f38139119..719ca6851625 100644\n--- a/doc/guides/linux_gsg/linux_eal_parameters.rst\n+++ b/doc/guides/linux_gsg/linux_eal_parameters.rst\n@@ -135,3 +135,8 @@ Other options\n local5\n local6\n local7\n+\n+* ``--log-timestamp``\n+\n+ Add a timestamp of seconds and microseconds to each log message\n+ written to standard output.\ndiff --git a/lib/eal/common/eal_common_options.c b/lib/eal/common/eal_common_options.c\nindex 005da4d12001..67fe6efb4526 100644\n--- a/lib/eal/common/eal_common_options.c\n+++ b/lib/eal/common/eal_common_options.c\n@@ -76,6 +76,7 @@ eal_long_options[] = {\n \t{OPT_IOVA_MODE,\t 1, NULL, OPT_IOVA_MODE_NUM },\n \t{OPT_LCORES, 1, NULL, OPT_LCORES_NUM },\n \t{OPT_LOG_LEVEL, 1, NULL, OPT_LOG_LEVEL_NUM },\n+\t{OPT_LOG_TIMESTAMP, 0, NULL, OPT_LOG_TIMESTAMP_NUM },\n \t{OPT_TRACE, 1, NULL, OPT_TRACE_NUM },\n \t{OPT_TRACE_DIR, 1, NULL, OPT_TRACE_DIR_NUM },\n \t{OPT_TRACE_BUF_SIZE, 1, NULL, OPT_TRACE_BUF_SIZE_NUM },\n@@ -1835,6 +1836,10 @@ eal_parse_common_option(int opt, const char *optarg,\n \t}\n \n #ifndef RTE_EXEC_ENV_WINDOWS\n+\tcase OPT_LOG_TIMESTAMP_NUM:\n+\t\tconf->log_timestamp = 1;\n+\t\tbreak;\n+\n \tcase OPT_TRACE_NUM: {\n \t\tif (eal_trace_args_save(optarg) < 0) {\n \t\t\tRTE_LOG(ERR, EAL, \"invalid parameters for --\"\n@@ -2194,6 +2199,7 @@ eal_common_usage(void)\n \t \" --\"OPT_PROC_TYPE\" Type of this process (primary|secondary|auto)\\n\"\n #ifndef RTE_EXEC_ENV_WINDOWS\n \t \" --\"OPT_SYSLOG\"=<facility> Set syslog facility\\n\"\n+\t \" --\"OPT_LOG_TIMESTAMP\" Timestamp log output\\n\"\n #endif\n \t \" --\"OPT_LOG_LEVEL\"=<level> Set global log level\\n\"\n \t \" --\"OPT_LOG_LEVEL\"=<type-match>:<level>\\n\"\ndiff --git a/lib/eal/common/eal_internal_cfg.h b/lib/eal/common/eal_internal_cfg.h\nindex 167ec501fa79..ca502d5dd365 100644\n--- a/lib/eal/common/eal_internal_cfg.h\n+++ b/lib/eal/common/eal_internal_cfg.h\n@@ -84,7 +84,10 @@ struct internal_config {\n \t/**< true if storing all pages within single files (per-page-size,\n \t * per-node) non-legacy mode only.\n \t */\n+\tuint8_t log_timestamp; /**< add timestamp to console output */\n+\tstruct timespec log_start_time; /**< monotonic clock when started */\n \tvolatile int syslog_facility;\t /**< facility passed to openlog() */\n+\n \t/** default interrupt mode for VFIO */\n \tvolatile enum rte_intr_mode vfio_intr_mode;\n \t/** the shared VF token for VFIO-PCI bound PF and VFs devices */\ndiff --git a/lib/eal/common/eal_options.h b/lib/eal/common/eal_options.h\nindex 3cc9cb641284..cc9723868e3c 100644\n--- a/lib/eal/common/eal_options.h\n+++ b/lib/eal/common/eal_options.h\n@@ -35,6 +35,8 @@ enum {\n \tOPT_LCORES_NUM,\n #define OPT_LOG_LEVEL \"log-level\"\n \tOPT_LOG_LEVEL_NUM,\n+#define OPT_LOG_TIMESTAMP \"log-timestamp\"\n+\tOPT_LOG_TIMESTAMP_NUM,\n #define OPT_TRACE \"trace\"\n \tOPT_TRACE_NUM,\n #define OPT_TRACE_DIR \"trace-dir\"\ndiff --git a/lib/eal/freebsd/eal.c b/lib/eal/freebsd/eal.c\nindex 104507b61514..ae3a736e862d 100644\n--- a/lib/eal/freebsd/eal.c\n+++ b/lib/eal/freebsd/eal.c\n@@ -394,7 +394,9 @@ eal_parse_args(int argc, char **argv)\n \t\t}\n \n \t\t/* eal_log_level_parse() already handled this option */\n-\t\tif (opt == OPT_LOG_LEVEL_NUM || opt == OPT_SYSLOG_NUM)\n+\t\tif (opt == OPT_LOG_LEVEL_NUM ||\n+\t\t opt == OPT_SYSLOG_NUM ||\n+\t\t opt == OPT_LOG_TIMESTAMP_NUM)\n \t\t\tcontinue;\n \n \t\tret = eal_parse_common_option(opt, optarg, internal_conf);\ndiff --git a/lib/eal/linux/eal.c b/lib/eal/linux/eal.c\nindex e30c44380e30..6deb694e7242 100644\n--- a/lib/eal/linux/eal.c\n+++ b/lib/eal/linux/eal.c\n@@ -611,7 +611,9 @@ eal_parse_args(int argc, char **argv)\n \t\t}\n \n \t\t/* eal_log_level_parse() already handled these */\n-\t\tif (opt == OPT_LOG_LEVEL_NUM || opt == OPT_SYSLOG_NUM)\n+\t\tif (opt == OPT_LOG_LEVEL_NUM ||\n+\t\t opt == OPT_SYSLOG_NUM ||\n+\t\t opt == OPT_LOG_TIMESTAMP_NUM)\n \t\t\tcontinue;\n \n \t\tret = eal_parse_common_option(opt, optarg, internal_conf);\ndiff --git a/lib/eal/unix/eal_log.c b/lib/eal/unix/eal_log.c\nindex 3bfe5853095f..172b332b8417 100644\n--- a/lib/eal/unix/eal_log.c\n+++ b/lib/eal/unix/eal_log.c\n@@ -5,7 +5,9 @@\n #include <getopt.h>\n #include <stdio.h>\n #include <sys/types.h>\n+#include <sys/uio.h>\n #include <syslog.h>\n+#include <time.h>\n #include <unistd.h>\n \n #include <rte_log.h>\n@@ -19,12 +21,38 @@\n * default log function\n */\n static ssize_t\n-console_log_write(__rte_unused void *c, const char *buf, size_t size)\n+console_log_write(void *c, const char *buf, size_t size)\n {\n+\tconst struct internal_config *internal_conf = c;\n \tssize_t ret;\n \n-\t/* write on stderr */\n-\tret = write(STDERR_FILENO, buf, size);\n+\t/* add optional timestamp for stderr */\n+\tif (internal_conf->log_timestamp) {\n+\t\tstruct iovec iov[2];\n+\t\tstruct timespec ts;\n+\t\tchar tbuf[64];\n+\n+\t\t/* format up monotonic timestamp */\n+\t\tclock_gettime(CLOCK_MONOTONIC, &ts);\n+\t\tts.tv_sec -= internal_conf->log_start_time.tv_sec;\n+\t\tts.tv_nsec -= internal_conf->log_start_time.tv_nsec;\n+\t\tif (ts.tv_nsec < 0) {\n+\t\t\t--ts.tv_sec;\n+\t\t\tts.tv_nsec += 1000000000ul;\n+\t\t}\n+\n+\t\t/* use writev to put timestamp and buf in single operation */\n+\t\tiov[0].iov_base = tbuf;\n+\t\tiov[0].iov_len = snprintf(tbuf, sizeof(tbuf), \"[%8lu.%06lu] \",\n+\t\t\t\t\t ts.tv_sec, ts.tv_nsec / 1000u);\n+\n+\t\t/* casts are to unconstify the buf */\n+\t\tiov[1].iov_base = (void *)(uintptr_t)buf;\n+\t\tiov[1].iov_len = size;\n+\t\tret = writev(STDERR_FILENO, iov, 2);\n+\t} else {\n+\t\tret = write(STDERR_FILENO, buf, size);\n+\t}\n \n \t/* Syslog error levels are from 0 to 7, so subtract 1 to convert */\n \tsyslog(rte_log_cur_msg_loglevel() - 1, \"%.*s\", (int)size, buf);\n@@ -82,6 +110,7 @@ eal_log_level_parse(int argc, char *const argv[])\n \t\tswitch (opt) {\n \t\tcase OPT_SYSLOG_NUM:\n \t\tcase OPT_LOG_LEVEL_NUM:\n+\t\tcase OPT_LOG_TIMESTAMP_NUM:\n \t\t\tif (eal_parse_common_option(opt, optarg, internal_conf) < 0)\n \t\t\t\treturn -1;\n \t\t\tbreak;\n@@ -111,13 +140,20 @@ eal_log_level_parse(int argc, char *const argv[])\n int\n eal_log_init(const char *id, int facility)\n {\n+\tstruct internal_config *internal_conf = eal_get_internal_configuration();\n \tFILE *log_stream;\n \n \t/* has user has already setup a log stream */\n \tif (eal_log_get_default())\n \t\treturn 0;\n \n-\tlog_stream = fopencookie(NULL, \"w+\", console_log_func);\n+\tif (internal_conf->process_type == RTE_PROC_PRIMARY &&\n+\t internal_conf->log_timestamp) {\n+\t\tif (clock_gettime(CLOCK_MONOTONIC, &internal_conf->log_start_time) < 0)\n+\t\t\treturn -1;\n+\t}\n+\n+\tlog_stream = fopencookie(internal_conf, \"w+\", console_log_func);\n \tif (log_stream == NULL)\n \t\treturn -1;\n \n", "prefixes": [ "v5", "6/6" ] }