Patch Detail
get:
Show a patch.
patch:
Update a patch.
put:
Update a patch.
GET /api/patches/139007/?format=api
{ "id": 139007, "url": "http://patchwork.dpdk.org/api/patches/139007/?format=api", "web_url": "http://patchwork.dpdk.org/project/dpdk/patch/20240330164433.50144-12-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": "<20240330164433.50144-12-stephen@networkplumber.org>", "list_archive_url": "https://inbox.dpdk.org/dev/20240330164433.50144-12-stephen@networkplumber.org", "date": "2024-03-30T16:42:22", "name": "[v20,11/14] log: add timestamp option", "commit_ref": null, "pull_url": null, "state": "new", "archived": false, "hash": "f7237868cec14ca60c5a011a4b0fe3ac3544e074", "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/20240330164433.50144-12-stephen@networkplumber.org/mbox/", "series": [ { "id": 31649, "url": "http://patchwork.dpdk.org/api/series/31649/?format=api", "web_url": "http://patchwork.dpdk.org/project/dpdk/list/?series=31649", "date": "2024-03-30T16:42:11", "name": "Logging unification and improvements", "version": 20, "mbox": "http://patchwork.dpdk.org/series/31649/mbox/" } ], "comments": "http://patchwork.dpdk.org/api/patches/139007/comments/", "check": "warning", "checks": "http://patchwork.dpdk.org/api/patches/139007/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 B84D343D85;\n\tSat, 30 Mar 2024 17:46:06 +0100 (CET)", "from mails.dpdk.org (localhost [127.0.0.1])\n\tby mails.dpdk.org (Postfix) with ESMTP id 1A790406B6;\n\tSat, 30 Mar 2024 17:45:04 +0100 (CET)", "from mail-oi1-f177.google.com (mail-oi1-f177.google.com\n [209.85.167.177])\n by mails.dpdk.org (Postfix) with ESMTP id 7AF33402E6\n for <dev@dpdk.org>; Sat, 30 Mar 2024 17:44:53 +0100 (CET)", "by mail-oi1-f177.google.com with SMTP id\n 5614622812f47-3c3aeef1385so2146662b6e.3\n for <dev@dpdk.org>; Sat, 30 Mar 2024 09:44:53 -0700 (PDT)", "from hermes.local (204-195-123-203.wavecable.com. [204.195.123.203])\n by smtp.gmail.com with ESMTPSA id\n by1-20020a056a02058100b005dc26144d96sm4192417pgb.75.2024.03.30.09.44.52\n (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256);\n Sat, 30 Mar 2024 09:44:52 -0700 (PDT)" ], "DKIM-Signature": "v=1; a=rsa-sha256; c=relaxed/relaxed;\n d=networkplumber-org.20230601.gappssmtp.com; s=20230601; t=1711817093;\n x=1712421893; 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=MoSMK2mRLCBWYunCS2Wzc1kUkaqeiNh1/1WXRKEZnlg=;\n b=k9XHnPGbIqJ0UkPrv8ytaZqoqhRC7+gAwYnkvPAGeOsjbE/Z+9nf1ER3YGlOhNU1dS\n ZLThbJvKIkjChvtXimcCoAYgWow1xVv+mfLMdUTBbBhhXKBNTfGmloafHeHpZ87C/4jK\n TYJH/zry91elB2uMo6LoZ2yDVAaIf9UOZrfgRm3S1QrJJSP8V5Ryv0xVRbWZ1fcxgTMC\n Y1Uk8TWZhg/pd0iBjUCO9Qex/uObkW2Cb9qYaLwJvaeUZ1QhbMPPivHqETTbR1zdieBl\n 8E7eA0GexXCzT0BYm60BWs5CsW2BwclWpKzIRj6L1I+qxkhVWmO+FELpdeJ1jCa1V7N9\n N+bg==", "X-Google-DKIM-Signature": "v=1; a=rsa-sha256; c=relaxed/relaxed;\n d=1e100.net; s=20230601; t=1711817093; x=1712421893;\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=MoSMK2mRLCBWYunCS2Wzc1kUkaqeiNh1/1WXRKEZnlg=;\n b=NyUIZhzj08yHlX1PtxdUTPf2CRIsXSejaNsTrNasvbrhfpvcWyLxX4tjbzwz9cVLjO\n /Qan6KBZTl6cVa32h13JwhoVyks2OMDPsmZzQnizmtYOd9TJpSPp7RrFHVo9q1P2Q28j\n MM1Q5G/lHmLh7Ho3WzSBWcOvDYDEdizWuezuwKhD3UdTzZtQA8sNGIdKyhRvvyTfHFJF\n 53WuWutGSqfWkydLiERRPyhXQ+qpV5oMCc/uw3xQfL+uQgqBtCf08CgVtWVMfhBbSXSr\n AFJsIwDh9+t5Fb0Q9M+oh42gTrri9oHwW45pC1++11B9IkENCsCqKzZvMaq0O2HJ9IZo\n 0b2w==", "X-Gm-Message-State": "AOJu0Yw7VpyhI2KblYb0gNCgt9br0oyguDPlb6R7FLEFbLVrpOSeVQeC\n HtrXfA2If7dq8vhIOoZQQlc1nEnJPBgQsHfzTXuYKq4k+kb59GG4c/RfdXLkfYVma7IecHRKrwh\n 1", "X-Google-Smtp-Source": "\n AGHT+IGht/wJD5RdFRjYbtX9szgGRRn52B5VPGJ0lW2OmnCeAbQjJQsIeotIA7SqRCprZ4oY2NssnA==", "X-Received": "by 2002:a05:6808:1211:b0:3c3:9fe6:2baf with SMTP id\n a17-20020a056808121100b003c39fe62bafmr6093255oil.20.1711817092763;\n Sat, 30 Mar 2024 09:44:52 -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 Dmitry Kozlyuk <dmitry.kozliuk@gmail.com>,\n Tyler Retzlaff <roretzla@linux.microsoft.com>,\n Pallavi Kadam <pallavi.kadam@intel.com>", "Subject": "[PATCH v20 11/14] log: add timestamp option", "Date": "Sat, 30 Mar 2024 09:42:22 -0700", "Message-ID": "<20240330164433.50144-12-stephen@networkplumber.org>", "X-Mailer": "git-send-email 2.43.0", "In-Reply-To": "<20240330164433.50144-1-stephen@networkplumber.org>", "References": "<20200814173441.23086-1-stephen@networkplumber.org>\n <20240330164433.50144-1-stephen@networkplumber.org>", "MIME-Version": "1.0", "Content-Type": "text/plain; charset=UTF-8", "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.\n\nThere are multiple timestamp formats similar to Linux dmesg.\nThe default is time relative since startup (when first\nstep of logging initialization is done by constructor).\nOther alternative formats are delta, ctime, reltime and iso formats.\n\nExample:\n$ dpdk-testpmd --log-timestamp -- -i\n[ 0.008610] EAL: Detected CPU lcores: 8\n[ 0.008634] EAL: Detected NUMA nodes: 1\n[ 0.008792] EAL: Detected static linkage of DPDK\n[ 0.010620] EAL: Multi-process socket /var/run/dpdk/rte/mp_socket\n[ 0.012618] EAL: Selected IOVA mode 'VA'\n[ 0.016675] testpmd: No probed ethernet devices\nInteractive-mode selected\n\nSigned-off-by: Stephen Hemminger <stephen@networkplumber.org>\n---\n app/test/test_eal_flags.c | 26 ++++\n doc/guides/prog_guide/log_lib.rst | 26 ++++\n lib/eal/common/eal_common_options.c | 14 +-\n lib/eal/common/eal_options.h | 2 +\n lib/eal/freebsd/eal.c | 6 +-\n lib/eal/linux/eal.c | 4 +-\n lib/eal/windows/eal.c | 4 +-\n lib/log/log.c | 10 +-\n lib/log/log_internal.h | 9 ++\n lib/log/log_private.h | 11 ++\n lib/log/log_timestamp.c | 210 ++++++++++++++++++++++++++++\n lib/log/meson.build | 6 +-\n lib/log/version.map | 1 +\n 13 files changed, 319 insertions(+), 10 deletions(-)\n create mode 100644 lib/log/log_timestamp.c", "diff": "diff --git a/app/test/test_eal_flags.c b/app/test/test_eal_flags.c\nindex 36e3185a10..e54f6e8b7f 100644\n--- a/app/test/test_eal_flags.c\n+++ b/app/test/test_eal_flags.c\n@@ -1054,6 +1054,19 @@ 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/* Try running with --log-timestamp=iso */\n+\tconst char * const argv24[] = {prgname, prefix, mp_flag,\n+\t\t\t\t \"--log-timestamp=iso\" };\n+\n+\t/* Try running with invalid timestamp */\n+\tconst char * const argv25[] = {prgname, prefix, mp_flag,\n+\t\t\t\t \"--log-timestamp=invalid\" };\n+\n+\n \t/* run all tests also applicable to FreeBSD first */\n \n \tif (launch_proc(argv0) == 0) {\n@@ -1161,6 +1174,19 @@ 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+\tif (launch_proc(argv24) != 0) {\n+\t\tprintf(\"Error - process did not run ok with --log-timestamp=iso parameter\\n\");\n+\t\tgoto fail;\n+\t}\n+\tif (launch_proc(argv25) == 0) {\n+\t\tprintf(\"Error - process did run ok with --log-timestamp=invalid 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 ff9d1b54a2..504eefe1d2 100644\n--- a/doc/guides/prog_guide/log_lib.rst\n+++ b/doc/guides/prog_guide/log_lib.rst\n@@ -59,6 +59,32 @@ For example::\n \n Within an application, the same result can be got using the ``rte_log_set_level_pattern()`` or ``rte_log_set_level_regex()`` APIs.\n \n+Log timestamp\n+~~~~~~~~~~~~~\n+\n+An optional timestamp can be added before each message\n+by adding the ``--log-timestamp`` option.\n+For example::\n+\n+\t/path/to/app --log-level=lib.*:debug --log-timestamp\n+\n+Multiple timestamp alternative timestamp formats are available:\n+\n+.. csv-table:: Log time stamp format\n+ :header: \"Format\", \"Description\", \"Example\"\n+ :widths: 6, 30, 32\n+\n+ \"ctime\", \"Unix ctime\", \"``[Wed Mar 20 07:26:12 2024]``\"\n+ \"delta\", \"Offset since last\", \"``[< 3.162373>]``\"\n+ \"reltime\", \"Seconds since last or time if minute changed\", \"``[ +3.001791]`` or ``[Mar20 07:26:12]``\"\n+ \"iso\", \"ISO-8601\", \"``[2024-03-20T07:26:12−07:00]``\"\n+\n+To prefix all console messages with ISO format time the syntax is::\n+\n+\t/path/to/app --log-timestamp=iso\n+\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 9ab512e8a1..5173835c2c 100644\n--- a/lib/eal/common/eal_common_options.c\n+++ b/lib/eal/common/eal_common_options.c\n@@ -74,6 +74,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, 2, 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@@ -1616,6 +1617,7 @@ eal_log_level_parse(int argc, char * const argv[])\n \t\tswitch (opt) {\n \t\tcase OPT_LOG_LEVEL_NUM:\n \t\tcase OPT_SYSLOG_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@@ -1843,7 +1845,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@@ -1851,7 +1853,14 @@ 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\tif (eal_log_timestamp(optarg) < 0) {\n+\t\t\tEAL_LOG(ERR, \"invalid parameters for --\"\n+\t\t\t\tOPT_LOG_TIMESTAMP);\n+\t\t\treturn -1;\n+\t\t}\n+\t\tbreak;\n \n #ifndef RTE_EXEC_ENV_WINDOWS\n \tcase OPT_TRACE_NUM: {\n@@ -2216,6 +2225,7 @@ eal_common_usage(void)\n \t \" --\"OPT_LOG_LEVEL\"=<type-match>:<level>\\n\"\n \t \" Set specific log level\\n\"\n \t \" --\"OPT_LOG_LEVEL\"=help Show log types and levels\\n\"\n+\t \" --\"OPT_LOG_TIMESTAMP\"[=<format>] Timestamp log output\\n\"\n #ifndef RTE_EXEC_ENV_WINDOWS\n \t \" --\"OPT_TRACE\"=<regex-match>\\n\"\n \t \" Enable trace based on regular expression trace name.\\n\"\ndiff --git a/lib/eal/common/eal_options.h b/lib/eal/common/eal_options.h\nindex f3f2e104f6..e24c9eca53 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 55ff27a4da..662a829ce8 100644\n--- a/lib/eal/freebsd/eal.c\n+++ b/lib/eal/freebsd/eal.c\n@@ -392,8 +392,10 @@ eal_parse_args(int argc, char **argv)\n \t\t\tgoto out;\n \t\t}\n \n-\t\t/* eal_log_level_parse() already handled these */\n-\t\tif (opt == OPT_LOG_LEVEL_NUM || opt == OPT_LOG_SYSLOG_NUM)\n+\t\t/* eal_log_level_parse() already handled these options */\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 b9a0fb1742..8cbea480e0 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 options */\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/windows/eal.c b/lib/eal/windows/eal.c\nindex 74b3ece30c..4283c920c8 100644\n--- a/lib/eal/windows/eal.c\n+++ b/lib/eal/windows/eal.c\n@@ -121,7 +121,9 @@ eal_parse_args(int argc, char **argv)\n \t\t}\n \n \t\t/* eal_log_level_parse() already handled these options */\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/log/log.c b/lib/log/log.c\nindex 979b20c3ef..71db4894fa 100644\n--- a/lib/log/log.c\n+++ b/lib/log/log.c\n@@ -21,7 +21,7 @@\n #include \"log_private.h\"\n \n #ifdef RTE_EXEC_ENV_WINDOWS\n-#define strdup _strdup\n+#include <rte_os_shim.h>\n #endif\n \n struct rte_log_dynamic_type {\n@@ -29,13 +29,13 @@ struct rte_log_dynamic_type {\n \tuint32_t loglevel;\n };\n \n-\n /** The rte_log structure. */\n static struct rte_logs {\n \tuint32_t type; /**< Bitfield with enabled logs. */\n \tuint32_t level; /**< Log level. */\n \tFILE *file; /**< Output file set by rte_openlog_stream, or NULL. */\n \tlog_print_t print_func;\n+\n \tsize_t dynamic_types_len;\n \tstruct rte_log_dynamic_type *dynamic_types;\n } rte_logs = {\n@@ -359,7 +359,6 @@ static const struct logtype logtype_strings[] = {\n RTE_INIT_PRIO(log_init, LOG)\n {\n \tuint32_t i;\n-\n \trte_log_set_global_level(RTE_LOG_DEBUG);\n \n \trte_logs.dynamic_types = calloc(RTE_LOGTYPE_FIRST_EXT_ID,\n@@ -510,6 +509,11 @@ eal_log_syslog(const char *mode __rte_unused)\n void\n eal_log_init(const char *id __rte_unused)\n {\n+\tif (log_timestamp_enabled())\n+\t\trte_logs.print_func = log_print_with_timestamp;\n+\telse\n+\t\trte_logs.print_func = vfprintf;\n+\n #if RTE_LOG_DP_LEVEL >= RTE_LOG_DEBUG\n \tRTE_LOG(NOTICE, EAL,\n \t\t\"Debug dataplane logs available - lower performance\\n\");\ndiff --git a/lib/log/log_internal.h b/lib/log/log_internal.h\nindex 3c46328e7b..7c7d44eed2 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@@ -39,4 +41,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+int eal_log_timestamp(const char *fmt);\n+\n+\n #endif /* LOG_INTERNAL_H */\ndiff --git a/lib/log/log_private.h b/lib/log/log_private.h\nindex 67d2463b2f..67cfe72fc6 100644\n--- a/lib/log/log_private.h\n+++ b/lib/log/log_private.h\n@@ -3,7 +3,18 @@\n #ifndef LOG_PRIVATE_H\n #define LOG_PRIVATE_H\n \n+/* Defined in limits.h on Linux */\n+#ifndef LINE_MAX\n+#define LINE_MAX\t2048 /* _POSIX2_LINE_MAX */\n+#endif\n+\n /* Note: same as vfprintf() */\n typedef int (*log_print_t)(FILE *f, const char *fmt, va_list ap);\n \n+bool log_timestamp_enabled(void);\n+ssize_t log_timestamp(char *tsbuf, size_t tsbuflen);\n+\n+__rte_format_printf(2, 0)\n+int log_print_with_timestamp(FILE *f, const char *format, va_list ap);\n+\n #endif /* LOG_PRIVATE_H */\ndiff --git a/lib/log/log_timestamp.c b/lib/log/log_timestamp.c\nnew file mode 100644\nindex 0000000000..04d8eba37b\n--- /dev/null\n+++ b/lib/log/log_timestamp.c\n@@ -0,0 +1,210 @@\n+/* SPDX-License-Identifier: BSD-3-Clause */\n+\n+#include <limits.h>\n+#include <stdarg.h>\n+#include <stdbool.h>\n+#include <stdint.h>\n+#include <stdio.h>\n+#include <stdlib.h>\n+#include <string.h>\n+#include <time.h>\n+\n+#include <rte_common.h>\n+\n+#ifdef RTE_EXEC_ENV_WINDOWS\n+#include <rte_os_shim.h>\n+#endif\n+\n+#include \"log_internal.h\"\n+#include \"log_private.h\"\n+\n+static enum {\n+\tLOG_TIMESTAMP_NONE = 0,\n+\tLOG_TIMESTAMP_TIME,\t/* time since start */\n+\tLOG_TIMESTAMP_DELTA,\t/* time since last message */\n+\tLOG_TIMESTAMP_RELTIME, /* relative time since last message */\n+\tLOG_TIMESTAMP_CTIME,\t/* Unix standard time format */\n+\tLOG_TIMESTAMP_ISO,\t/* ISO8601 time format */\n+} log_time_format;\n+\n+static struct {\n+\tstruct timespec started; /* when log was initialized */\n+\tstruct timespec previous; /* when last msg was printed */\n+} log_time;\n+\n+/* Set the log timestamp format */\n+int\n+eal_log_timestamp(const char *str)\n+{\n+\tif (str == NULL)\n+\t\tlog_time_format = LOG_TIMESTAMP_TIME;\n+\telse if (strcmp(str, \"notime\") == 0)\n+\t\tlog_time_format = LOG_TIMESTAMP_NONE;\n+\telse if (strcmp(str, \"reltime\") == 0)\n+\t\tlog_time_format = LOG_TIMESTAMP_RELTIME;\n+\telse if (strcmp(str, \"delta\") == 0)\n+\t\tlog_time_format = LOG_TIMESTAMP_DELTA;\n+\telse if (strcmp(str, \"ctime\") == 0)\n+\t\tlog_time_format = LOG_TIMESTAMP_CTIME;\n+\telse if (strcmp(str, \"iso\") == 0)\n+\t\tlog_time_format = LOG_TIMESTAMP_ISO;\n+\telse\n+\t\treturn -1;\n+\n+\treturn 0;\n+}\n+\n+bool\n+log_timestamp_enabled(void)\n+{\n+\treturn log_time_format != LOG_TIMESTAMP_NONE;\n+}\n+\n+/* Subtract two timespec values and handle wraparound */\n+static struct timespec\n+timespec_sub(const struct timespec *t0, const struct timespec *t1)\n+{\n+\tstruct timespec ts;\n+\n+\tts.tv_sec = t0->tv_sec - t1->tv_sec;\n+\tts.tv_nsec = t0->tv_nsec - t1->tv_nsec;\n+\tif (ts.tv_nsec < 0) {\n+\t\tts.tv_sec--;\n+\t\tts.tv_nsec += 1000000000L;\n+\t}\n+\treturn ts;\n+}\n+\n+/*\n+ * Format current timespec into ISO8601 format.\n+ * Surprisingly, can't just use strftime() for this;\n+ * since want microseconds and the timezone offset format differs.\n+ */\n+static ssize_t\n+format_iso8601(char *tsbuf, size_t tsbuflen, const struct timespec *now)\n+{\n+\tstruct tm *tm, tbuf;\n+\tchar dbuf[64]; /* \"2024-05-01T22:11:00\" */\n+\tchar zbuf[16] = { }; /* \"+0800\" */\n+\n+\ttm = localtime_r(&now->tv_sec, &tbuf);\n+\n+\t/* make \"2024-05-01T22:11:00,123456+0100\" */\n+\tif (strftime(dbuf, sizeof(dbuf), \"%Y-%m-%dT%H:%M:%S\", tm) == 0)\n+\t\treturn 0;\n+\n+\t/* convert timezone to +hhmm */\n+\tif (strftime(zbuf, sizeof(zbuf), \"%z\", tm) == 0)\n+\t\treturn 0;\n+\n+\t/* the result for strftime is \"+hhmm\" but ISO wants \"+hh:mm\" */\n+\treturn snprintf(tsbuf, tsbuflen, \"%s,%06lu%.3s:%.2s\",\n+\t\t\tdbuf, now->tv_nsec / 1000u,\n+\t\t\tzbuf, zbuf + 3);\n+}\n+\n+/*\n+ * Make a timestamp where if the minute, hour or day has\n+ * changed from the last message, then print abbreviated\n+ * \"Month day hour:minute\" format.\n+ * Otherwise print delta from last printed message as +sec.usec\n+ */\n+static ssize_t\n+format_reltime(char *tsbuf, size_t tsbuflen, const struct timespec *now)\n+{\n+\tstruct tm *tm, tbuf;\n+\tstatic struct tm last_tm;\n+\tstruct timespec delta;\n+\n+\ttm = localtime_r(&now->tv_sec, &tbuf);\n+\tdelta = timespec_sub(now, &log_time.previous);\n+\tlog_time.previous = *now;\n+\n+\t/* if minute, day, hour hasn't changed then print delta */\n+\tif (tm->tm_min != last_tm.tm_min ||\n+\t tm->tm_hour != last_tm.tm_hour ||\n+\t tm->tm_yday != last_tm.tm_yday) {\n+\t\tlast_tm = *tm;\n+\t\treturn strftime(tsbuf, tsbuflen, \"%b%d %H:%M\", tm);\n+\t} else {\n+\t\treturn snprintf(tsbuf, tsbuflen, \"+%3lu.%06lu\",\n+\t\t\t\t(unsigned long)delta.tv_sec,\n+\t\t\t\t(unsigned long)delta.tv_nsec / 1000u);\n+\t}\n+}\n+\n+/* Format up a timestamp based on current format */\n+ssize_t\n+log_timestamp(char *tsbuf, size_t tsbuflen)\n+{\n+\tstruct timespec now, delta;\n+\n+\tswitch (log_time_format) {\n+\tcase LOG_TIMESTAMP_NONE:\n+\t\treturn 0;\n+\n+\tcase LOG_TIMESTAMP_TIME:\n+\t\tif (clock_gettime(CLOCK_MONOTONIC, &now) < 0)\n+\t\t\treturn 0;\n+\n+\t\tdelta = timespec_sub(&now, &log_time.started);\n+\n+\t\treturn snprintf(tsbuf, tsbuflen, \"%6lu.%06lu\",\n+\t\t\t\t(unsigned long)delta.tv_sec,\n+\t\t\t\t(unsigned long)delta.tv_nsec / 1000u);\n+\n+\tcase LOG_TIMESTAMP_DELTA:\n+\t\tif (clock_gettime(CLOCK_MONOTONIC, &now) < 0)\n+\t\t\treturn 0;\n+\n+\t\tdelta = timespec_sub(&now, &log_time.previous);\n+\t\tlog_time.previous = now;\n+\n+\t\treturn snprintf(tsbuf, tsbuflen, \"<%6lu.%06lu>\",\n+\t\t\t\t(unsigned long)delta.tv_sec,\n+\t\t\t\t(unsigned long)delta.tv_nsec / 1000u);\n+\n+\tcase LOG_TIMESTAMP_RELTIME:\n+\t\tif (clock_gettime(CLOCK_REALTIME, &now) < 0)\n+\t\t\treturn 0;\n+\n+\t\treturn format_reltime(tsbuf, tsbuflen, &now);\n+\n+\tcase LOG_TIMESTAMP_CTIME:\n+\t\tif (clock_gettime(CLOCK_REALTIME, &now) < 0)\n+\t\t\treturn 0;\n+\n+\t\t/* trncate to remove newline from ctime result */\n+\t\treturn snprintf(tsbuf, tsbuflen, \"%.24s\", ctime(&now.tv_sec));\n+\n+\tcase LOG_TIMESTAMP_ISO:\n+\t\tif (clock_gettime(CLOCK_REALTIME, &now) < 0)\n+\t\t\treturn 0;\n+\n+\t\treturn format_iso8601(tsbuf, tsbuflen, &now);\n+\t}\n+\n+\treturn 0;\n+}\n+\n+/* print timestamp before message */\n+int\n+log_print_with_timestamp(FILE *f, const char *format, va_list ap)\n+{\n+\tchar tsbuf[128];\n+\tchar msgbuf[LINE_MAX];\n+\n+\tif (log_timestamp(tsbuf, sizeof(tsbuf)) > 0) {\n+\t\tvsnprintf(msgbuf, sizeof(msgbuf), format, ap);\n+\t\treturn fprintf(f, \"[%s] %s\", tsbuf, msgbuf);\n+\t}\n+\n+\t/* fall back when timestamp is unavailable */\n+\treturn vfprintf(f, format, ap);\n+}\n+\n+RTE_INIT_PRIO(log_timestamp_init, LOG)\n+{\n+\tclock_gettime(CLOCK_MONOTONIC, &log_time.started);\n+\tlog_time.previous = log_time.started;\n+}\ndiff --git a/lib/log/meson.build b/lib/log/meson.build\nindex 891f77a237..04235f6ee5 100644\n--- a/lib/log/meson.build\n+++ b/lib/log/meson.build\n@@ -2,5 +2,9 @@\n # Copyright(c) 2023 Intel Corporation\n \n includes += global_inc\n-sources = files('log.c')\n+sources = files(\n+ 'log.c',\n+ 'log_timestamp.c',\n+)\n+\n headers = files('rte_log.h')\ndiff --git a/lib/log/version.map b/lib/log/version.map\nindex 32b9680c31..14d6681a5f 100644\n--- a/lib/log/version.map\n+++ b/lib/log/version.map\n@@ -30,5 +30,6 @@ INTERNAL {\n \teal_log_save_pattern;\n \teal_log_save_regexp;\n \teal_log_syslog;\n+\teal_log_timestamp;\n \trte_eal_log_cleanup;\n };\n", "prefixes": [ "v20", "11/14" ] }