Patch Detail
get:
Show a patch.
patch:
Update a patch.
put:
Update a patch.
GET /api/patches/138476/?format=api
{ "id": 138476, "url": "http://patchwork.dpdk.org/api/patches/138476/?format=api", "web_url": "http://patchwork.dpdk.org/project/dpdk/patch/20240318220432.7486-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": "<20240318220432.7486-6-stephen@networkplumber.org>", "list_archive_url": "https://inbox.dpdk.org/dev/20240318220432.7486-6-stephen@networkplumber.org", "date": "2024-03-18T22:03:01", "name": "[v9,5/5] eal: add option to put timestamp on console output", "commit_ref": null, "pull_url": null, "state": "superseded", "archived": true, "hash": "e321564b749bf7ed312b275ca906d5f3522d1775", "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/20240318220432.7486-6-stephen@networkplumber.org/mbox/", "series": [ { "id": 31551, "url": "http://patchwork.dpdk.org/api/series/31551/?format=api", "web_url": "http://patchwork.dpdk.org/project/dpdk/list/?series=31551", "date": "2024-03-18T22:02:56", "name": "Logging unification and timestamp", "version": 9, "mbox": "http://patchwork.dpdk.org/series/31551/mbox/" } ], "comments": "http://patchwork.dpdk.org/api/patches/138476/comments/", "check": "fail", "checks": "http://patchwork.dpdk.org/api/patches/138476/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 E00A643CEE;\n\tMon, 18 Mar 2024 23:05:17 +0100 (CET)", "from mails.dpdk.org (localhost [127.0.0.1])\n\tby mails.dpdk.org (Postfix) with ESMTP id C041040DDC;\n\tMon, 18 Mar 2024 23:04:53 +0100 (CET)", "from mail-pf1-f175.google.com (mail-pf1-f175.google.com\n [209.85.210.175])\n by mails.dpdk.org (Postfix) with ESMTP id 5008040A80\n for <dev@dpdk.org>; Mon, 18 Mar 2024 23:04:50 +0100 (CET)", "by mail-pf1-f175.google.com with SMTP id\n d2e1a72fcca58-6e46dcd8feaso2884084b3a.2\n for <dev@dpdk.org>; Mon, 18 Mar 2024 15:04:50 -0700 (PDT)", "from hermes.local (204-195-123-141.wavecable.com. [204.195.123.141])\n by smtp.gmail.com with ESMTPSA id\n y6-20020a637d06000000b005dc88b232a5sm7747140pgc.26.2024.03.18.15.04.48\n (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256);\n Mon, 18 Mar 2024 15:04:48 -0700 (PDT)" ], "DKIM-Signature": "v=1; a=rsa-sha256; c=relaxed/relaxed;\n d=networkplumber-org.20230601.gappssmtp.com; s=20230601; t=1710799489;\n x=1711404289; darn=dpdk.org;\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=mm+yD9goF61yhxXIeT7u6e0EGZS37olmLkVeOSQvEYg=;\n b=slokKUREpEXYLmj/5IWwAb7SW5Qh7rR7bTS+MZ/svb7oO8b6okftQkbM8YponuYNP2\n B5V7uKwAlJ6I3rad+c5RiuXFfmrqAWpu3g+DFFH1ymmPlKCmDfndh/db0Wvl+A/RUJlD\n 5PIwIJu1dKGMTzDcYp/KxAVbIjXPKX45V962TykI9QLHBOMtTPyHrv1U8E669chHnlOe\n lbWG4Wvfwp3EmM15I/QGvlrW5RivSZD+NtjGWxu/mSTAtQto8aFv0s9HLF6sheafM/Gc\n LUnH1MsKAdsQgbX5Q+M66DNQiDOd51tczbPEN2Kkm8q8HBCJaaBM7cxsMMAyEL+Szegc\n Fmlg==", "X-Google-DKIM-Signature": "v=1; a=rsa-sha256; c=relaxed/relaxed;\n d=1e100.net; s=20230601; t=1710799489; x=1711404289;\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=mm+yD9goF61yhxXIeT7u6e0EGZS37olmLkVeOSQvEYg=;\n b=cAQ6ImLoxaVAlA1zFmk8NyHKbBaQSVsre+db5IFenA6nmWLja5Lysjwm0JM8MZt0je\n Seyzs9nnfWuVu/WUDOk9oY3UDffbO1JWUnRHUB1ZzH22drob0vzX69WZdTDazEjlXKEV\n 70xzRzO3AWTkexXwLsGgDxRZq2XKGuzO+OHLlKjZeetnCObPwVq2V6gN4RHWLepJymU0\n yVTLqxzRLn4cmZKs1z3+VuCqp/y1nM0tCRoL+mxZuAkY4COO7GWAKWYPkVXm65VGbG3b\n n6HyMDaYyLt1z+eBj8hWO4562UBez/mEES/jRomJaQC3qYn+gOv3MCv4fIuCPGKeetQe\n Bn5g==", "X-Gm-Message-State": "AOJu0Yw7Splh6QzqtHcf3WBbycZGPBX3SKpvPdoE8JpwcyKw6gVe8dkE\n If8JCqauc4n54ojzRMMlT+64PN7zqJ54oK7RZUQPPuEsaMY/0fL5qNaebhVDYB3JTZ3L8ZWUDJz\n H", "X-Google-Smtp-Source": "\n AGHT+IH70RiyMjPPc43se9rub7eK5uF1h+/FxahRP6Ycse7HJe69kQpRTu8adjooc20MQQPucu7W5g==", "X-Received": "by 2002:a05:6a00:850:b0:6e6:b4e0:c3db with SMTP id\n q16-20020a056a00085000b006e6b4e0c3dbmr1139705pfk.24.1710799489332;\n Mon, 18 Mar 2024 15:04:49 -0700 (PDT)", "From": "Stephen Hemminger <stephen@networkplumber.org>", "To": "dev@dpdk.org", "Cc": "Stephen Hemminger <stephen@networkplumber.org>", "Subject": "[PATCH v9 5/5] eal: add option to put timestamp on console output", "Date": "Mon, 18 Mar 2024 15:03:01 -0700", "Message-ID": "<20240318220432.7486-6-stephen@networkplumber.org>", "X-Mailer": "git-send-email 2.43.0", "In-Reply-To": "<20240318220432.7486-1-stephen@networkplumber.org>", "References": "<20200814173441.23086-1-stephen@networkplumber.org>\n <20240318220432.7486-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\nThis logging skips the unnecessary step of going through stdio,\nwhich makes it more robust against being called in interrupt\nhandlers etc.\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 app/test/test_eal_flags.c | 9 ++++++++\n doc/guides/prog_guide/log_lib.rst | 10 +++++++++\n lib/eal/common/eal_common_options.c | 10 +++++++--\n lib/eal/common/eal_options.h | 2 ++\n lib/log/log_internal.h | 9 ++++++++\n lib/log/log_unix.c | 32 +++++++++++++++++++++++++++--\n lib/log/log_windows.c | 6 ++++++\n lib/log/version.map | 1 +\n 8 files changed, 75 insertions(+), 4 deletions(-)", "diff": "diff --git a/app/test/test_eal_flags.c b/app/test/test_eal_flags.c\nindex 6cb4b0675730..07a038fb6051 100644\n--- a/app/test/test_eal_flags.c\n+++ b/app/test/test_eal_flags.c\n@@ -1055,6 +1055,10 @@ test_misc_flags(void)\n \tconst char * const argv22[] = {prgname, prefix, mp_flag,\n \t\t\t\t \"--huge-worker-stack=512\"};\n \n+\t/* Try running with --log-timestamp */\n+\tconst char * const argv23[] = {prgname, prefix, mp_flag,\n+\t\t\t\t \"--log-timestamp\" };\n+\n \t/* run all tests also applicable to FreeBSD first */\n \n \tif (launch_proc(argv0) == 0) {\n@@ -1162,6 +1166,11 @@ test_misc_flags(void)\n \t\tprintf(\"Error - process did not run ok with --huge-worker-stack=size parameter\\n\");\n \t\tgoto fail;\n \t}\n+\tif (launch_proc(argv23) != 0) {\n+\t\tprintf(\"Error - process did not run ok with --log-timestamp parameter\\n\");\n+\t\tgoto fail;\n+\t}\n+\n \n \trmdir(hugepath_dir3);\n \trmdir(hugepath_dir2);\ndiff --git a/doc/guides/prog_guide/log_lib.rst b/doc/guides/prog_guide/log_lib.rst\nindex aacb36c36ce0..1d6b2e3cea5d 100644\n--- a/doc/guides/prog_guide/log_lib.rst\n+++ b/doc/guides/prog_guide/log_lib.rst\n@@ -73,6 +73,16 @@ For example::\n \t/path/to/app --syslog local0\n \n \n+Console timestamp\n+~~~~~~~~~~~~~~~~~\n+\n+On Linux and FreeBSD, an optional timestamp can be added before each\n+message by adding the ``--log-timestamp`` option.\n+For example::\n+\n+\t/path/to/app --log-level=lib.*:debug --log-timestamp\n+\n+\n Using Logging APIs to Generate Log Messages\n -------------------------------------------\n \ndiff --git a/lib/eal/common/eal_common_options.c b/lib/eal/common/eal_common_options.c\nindex 7310d10dfd78..9bc95433d27c 100644\n--- a/lib/eal/common/eal_common_options.c\n+++ b/lib/eal/common/eal_common_options.c\n@@ -77,6 +77,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@@ -1663,6 +1664,7 @@ eal_log_level_parse(int argc, char * const argv[])\n \n \t\tswitch (opt) {\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@@ -1890,7 +1892,7 @@ eal_parse_common_option(int opt, const char *optarg,\n \t\tbreak;\n #endif\n \n-\tcase OPT_LOG_LEVEL_NUM: {\n+\tcase OPT_LOG_LEVEL_NUM:\n \t\tif (eal_parse_log_level(optarg) < 0) {\n \t\t\tEAL_LOG(ERR,\n \t\t\t\t\"invalid parameters for --\"\n@@ -1898,7 +1900,10 @@ eal_parse_common_option(int opt, const char *optarg,\n \t\t\treturn -1;\n \t\t}\n \t\tbreak;\n-\t}\n+\n+\tcase OPT_LOG_TIMESTAMP_NUM:\n+\t\teal_log_enable_timestamp();\n+\t\tbreak;\n \n #ifndef RTE_EXEC_ENV_WINDOWS\n \tcase OPT_TRACE_NUM: {\n@@ -2261,6 +2266,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_options.h b/lib/eal/common/eal_options.h\nindex f3f2e104f6d7..e24c9eca53ca 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/log/log_internal.h b/lib/log/log_internal.h\nindex c77e687e28bc..1af27fe8f9d3 100644\n--- a/lib/log/log_internal.h\n+++ b/lib/log/log_internal.h\n@@ -5,8 +5,10 @@\n #ifndef LOG_INTERNAL_H\n #define LOG_INTERNAL_H\n \n+#include <stdbool.h>\n #include <stdio.h>\n #include <stdint.h>\n+#include <time.h>\n \n #include <rte_compat.h>\n \n@@ -44,4 +46,11 @@ const char *eal_log_level2str(uint32_t level);\n __rte_internal\n void rte_eal_log_cleanup(void);\n \n+/*\n+ * Add timestamp to console logs\n+ */\n+__rte_internal\n+void eal_log_enable_timestamp(void);\n+\n+\n #endif /* LOG_INTERNAL_H */\ndiff --git a/lib/log/log_unix.c b/lib/log/log_unix.c\nindex a415bae5774d..71ce366b6825 100644\n--- a/lib/log/log_unix.c\n+++ b/lib/log/log_unix.c\n@@ -2,24 +2,52 @@\n * Copyright(c) 2010-2014 Intel Corporation\n */\n \n+#include <stdbool.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 \n #include \"log_internal.h\"\n \n+static bool timestamp_enabled;\n+static struct timespec log_started;\n+\n+void\n+eal_log_enable_timestamp(void)\n+{\n+\ttimestamp_enabled = true;\n+\tclock_gettime(CLOCK_MONOTONIC, &log_started);\n+}\n+\n /*\n * default log function\n */\n static ssize_t\n console_log_write(__rte_unused void *c, const char *buf, size_t size)\n {\n+\tstruct timespec ts;\n \tssize_t ret;\n \n-\t/* write on stderr */\n-\tret = fwrite(buf, 1, size, stderr);\n+\tif (timestamp_enabled) {\n+\t\tclock_gettime(CLOCK_MONOTONIC, &ts);\n+\t\tts.tv_sec -= log_started.tv_sec;\n+\t\tts.tv_nsec -= log_started.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\tret = fprintf(stderr, \"[%8lu.%06lu] %.*s\",\n+\t\t\t ts.tv_sec, ts.tv_nsec / 1000u,\n+\t\t\t (int) size, buf);\n+\t} else {\n+\t\tret = fwrite(buf, 1, size, stderr);\n+\t}\n \tfflush(stderr);\n \n \t/* Syslog error levels are from 0 to 7, so subtract 1 to convert */\ndiff --git a/lib/log/log_windows.c b/lib/log/log_windows.c\nindex a6a08895501e..0c471bfb15f6 100644\n--- a/lib/log/log_windows.c\n+++ b/lib/log/log_windows.c\n@@ -6,6 +6,12 @@\n #include <rte_log.h>\n #include \"log_internal.h\"\n \n+void\n+eal_log_enable_timestamp(void)\n+{\n+\t/* not implemented */\n+}\n+\n /* set the log to default function, called during eal init process. */\n int\n eal_log_init(__rte_unused const char *id, __rte_unused int facility)\ndiff --git a/lib/log/version.map b/lib/log/version.map\nindex 6ecc656d1d65..32c555f29e79 100644\n--- a/lib/log/version.map\n+++ b/lib/log/version.map\n@@ -25,6 +25,7 @@ DPDK_24 {\n INTERNAL {\n \tglobal:\n \n+\teal_log_enable_timestamp;\n \teal_log_get_default;\n \teal_log_init;\n \teal_log_level2str;\n", "prefixes": [ "v9", "5/5" ] }