Patch Detail
get:
Show a patch.
patch:
Update a patch.
put:
Update a patch.
GET /api/patches/129008/?format=api
{ "id": 129008, "url": "http://patchwork.dpdk.org/api/patches/129008/?format=api", "web_url": "http://patchwork.dpdk.org/project/dpdk/patch/20230626184223.155390-6-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": "<20230626184223.155390-6-stephen@networkplumber.org>", "list_archive_url": "https://inbox.dpdk.org/dev/20230626184223.155390-6-stephen@networkplumber.org", "date": "2023-06-26T18:42:16", "name": "[v4,5/5] eal: add option to put timestamp on console output", "commit_ref": null, "pull_url": null, "state": "superseded", "archived": true, "hash": "e27a0d95acd0a8b043b7f213e7fba961ada77c2c", "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/20230626184223.155390-6-stephen@networkplumber.org/mbox/", "series": [ { "id": 28655, "url": "http://patchwork.dpdk.org/api/series/28655/?format=api", "web_url": "http://patchwork.dpdk.org/project/dpdk/list/?series=28655", "date": "2023-06-26T18:42:11", "name": "Logging related patchs", "version": 4, "mbox": "http://patchwork.dpdk.org/series/28655/mbox/" } ], "comments": "http://patchwork.dpdk.org/api/patches/129008/comments/", "check": "fail", "checks": "http://patchwork.dpdk.org/api/patches/129008/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 2C07142D5F;\n\tMon, 26 Jun 2023 20:43:26 +0200 (CEST)", "from mails.dpdk.org (localhost [127.0.0.1])\n\tby mails.dpdk.org (Postfix) with ESMTP id ACBC342D2F;\n\tMon, 26 Jun 2023 20:42:59 +0200 (CEST)", "from mail-pj1-f51.google.com (mail-pj1-f51.google.com\n [209.85.216.51]) by mails.dpdk.org (Postfix) with ESMTP id D447C42D0C\n for <dev@dpdk.org>; Mon, 26 Jun 2023 20:42:56 +0200 (CEST)", "by mail-pj1-f51.google.com with SMTP id\n 98e67ed59e1d1-262c6718d14so742169a91.2\n for <dev@dpdk.org>; Mon, 26 Jun 2023 11:42:56 -0700 (PDT)", "from hermes.local (204-195-120-218.wavecable.com. [204.195.120.218])\n by smtp.gmail.com with ESMTPSA id\n h17-20020a17090adb9100b0024e37e0a67dsm4846577pjv.20.2023.06.26.11.42.54\n (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256);\n Mon, 26 Jun 2023 11:42:55 -0700 (PDT)" ], "DKIM-Signature": "v=1; a=rsa-sha256; c=relaxed/relaxed;\n d=networkplumber-org.20221208.gappssmtp.com; s=20221208; t=1687804976;\n x=1690396976;\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=wMqTqBB9Kct1SM96bVI30Qu0Qv4SGifI7jxxJhBYRgo=;\n b=ljxsaqScTFbh/HDBEEulqjK9YVC2IFJPCiakV57yEwBNfrW0H9Kae8YljdcPMxWDn0\n +sy77wrxF9Nz0kUEQSEShICn+bjHR1KxciUu6biqfZGoN/Z0EWuCZjXz8d4lnh3m8ewV\n V1Si0OpGNRJyoYZ6dKe5w3PWyJhNhjDVCor88JIfV3hlGlC6MJ5Z9S1IPPGRZ9Vhcw1S\n XUWct4VEklva95/J+NGsJJ97wTC1rNIAKb6S5vGu5gZqi7/dE0GcdFg/KAC9QgVLm8Cl\n pncOjzb2sArKCA1lZe8S9fL7v23ykuKoO569x216sqX5PZ16XhM2+WdVrc6BEAMzU6jZ\n YeNg==", "X-Google-DKIM-Signature": "v=1; a=rsa-sha256; c=relaxed/relaxed;\n d=1e100.net; s=20221208; t=1687804976; x=1690396976;\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=wMqTqBB9Kct1SM96bVI30Qu0Qv4SGifI7jxxJhBYRgo=;\n b=Sw+DJAvU58Uc3Tftl8fccwiW7dbkY9GIq1sD/iROq4OnwK78eLKuA2HTCt59e5NM0A\n SDuxu3nEF5yOv3SmVzCXWu5ChJyDj9pagGdG0+3t6sV4HxpyfT7ihtXQ/8K8piD/cCRB\n 4SPe/Zz52NVJrRZkFVvoqW7zjdzgheKOmTRWJYoZnSagu7vjC58J2QQ3b0uQU4n7BHDl\n 69ND1w1tpmgnBTw8KREHyWbuRyt5YjNvzzOpCw/jCCosNecFc+HFXo5HogGwwHl87uIC\n FO6ibHMsUu7B04r8zVEAcC2oyMN3bYDxGDe1jxlWUxNmdxQcZBjPAMq2+A9hXLtBRRjg\n +P3w==", "X-Gm-Message-State": "AC+VfDwcwan+2wvJo1SKpQdJknVQ93u7Dm8ee0wa43zYdaa3LVT1Hra6\n EQgh8/BG7CkvfKFQCoOjU1YymwgQOgAOFfTlBOISRA==", "X-Google-Smtp-Source": "\n ACHHUZ6NEPe4CcGoE+pdJ9FCylO0GQ/raJj8FiEREMurNsdy20UMwBWJ7vosrLjaLkx6bH1Hrwz0vA==", "X-Received": "by 2002:a17:90a:19ca:b0:261:3202:3c4e with SMTP id\n 10-20020a17090a19ca00b0026132023c4emr6682108pjj.25.1687804975760;\n Mon, 26 Jun 2023 11:42:55 -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>", "Subject": "[PATCH v4 5/5] eal: add option to put timestamp on console output", "Date": "Mon, 26 Jun 2023 11:42:16 -0700", "Message-Id": "<20230626184223.155390-6-stephen@networkplumber.org>", "X-Mailer": "git-send-email 2.39.2", "In-Reply-To": "<20230626184223.155390-1-stephen@networkplumber.org>", "References": "<20200814173441.23086-1-stephen@networkplumber.org>\n <20230626184223.155390-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\nExample:\n$ dpdk-testpmd --log-timestamp -- -i\n[ 0.007615] EAL: Detected CPU lcores: 16\n[ 0.007657] EAL: Detected NUMA nodes: 1\n[ 0.007878] EAL: Detected static linkage of DPDK\n[ 0.009469] EAL: Multi-process socket /var/run/dpdk/rte/mp_socket\n[ 0.012175] EAL: Selected IOVA mode 'VA'\n[ 0.120016] testpmd: No probed ethernet devices\nInteractive-mode selected\n[ 0.155959] testpmd: create a new mbuf pool <mb_pool_0>: n=267456, size=2176, socket=0\n[ 0.155990] 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 | 36 +++++++++++++++++--\n 8 files changed, 61 insertions(+), 4 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 03059336987d..c6c74cc31e9c 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\" 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..1a1a7fdcfa8c 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+\tvolatile uint8_t log_timestamp; /**< add timestamp to console output */\n \tvolatile int syslog_facility;\t /**< facility passed to openlog() */\n+\tstruct timespec log_start_time;\t /**< when logging was started */\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 d3aac3d628a8..5c7cea8809bd 100644\n--- a/lib/eal/freebsd/eal.c\n+++ b/lib/eal/freebsd/eal.c\n@@ -388,6 +388,7 @@ eal_log_level_parse(int argc, char **argv)\n \n \t\tswitch (opt) {\n \t\tcase OPT_SYSLOG_NUM:\t\t/* fallthrough */\n+\t\tcase OPT_LOG_TIMESTAMP_NUM:\t/* fallthrough */\n \t\tcase OPT_LOG_LEVEL_NUM:\n \t\t\tif (eal_parse_common_option(opt, optarg, internal_conf) < 0)\n \t\t\t\tgoto error;\n@@ -436,7 +437,8 @@ 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_SYSLOG_NUM ||\n+\t\t opt == OPT_LOG_TIMESTAMP_NUM || opt == OPT_LOG_LEVEL_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 51c4ec75d57b..051f9ad7f5bf 100644\n--- a/lib/eal/linux/eal.c\n+++ b/lib/eal/linux/eal.c\n@@ -568,6 +568,7 @@ eal_log_level_parse(int argc, char **argv)\n \n \t\tswitch (opt) {\n \t\tcase OPT_SYSLOG_NUM:\t\t/* fallthrough */\n+\t\tcase OPT_LOG_TIMESTAMP_NUM:\t/* fallthrough */\n \t\tcase OPT_LOG_LEVEL_NUM:\n \t\t\tif (eal_parse_common_option(opt, optarg, internal_conf) < 0)\n \t\t\t\tgoto error;\n@@ -650,7 +651,8 @@ 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_SYSLOG_NUM ||\n+\t\t opt == OPT_LOG_TIMESTAMP_NUM || opt == OPT_LOG_LEVEL_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 baa721021991..f65a22612310 100644\n--- a/lib/eal/unix/eal_log.c\n+++ b/lib/eal/unix/eal_log.c\n@@ -4,12 +4,15 @@\n \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 \n #include \"eal_log.h\"\n+#include \"eal_private.h\"\n \n /*\n * default log function\n@@ -17,10 +20,36 @@\n static ssize_t\n console_log_write(__rte_unused void *c, const char *buf, size_t size)\n {\n+\tconst struct internal_config *internal_conf = eal_get_internal_configuration();\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@@ -47,8 +76,11 @@ static cookie_io_functions_t console_log_func = {\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+\tclock_gettime(CLOCK_MONOTONIC, &internal_conf->log_start_time);\n+\n \tlog_stream = fopencookie(NULL, \"w+\", console_log_func);\n \tif (log_stream == NULL)\n \t\treturn -1;\n", "prefixes": [ "v4", "5/5" ] }